Sometimes a user may remain with his presence as on_the_phone after the conversation has finished

Description

These were the sequence of events generated when the user received a call, had the conversation and then hanged up. But the presence of this user remained as on the phone.

2005.11.01 11:05:20 Asterisk-IM: Processing NewChannel:RINGING event channel : SIP/7714-84ad

2005.11.01 11:05:20 Asterisk-IM RingTask called for user PhoneUser{id=46, username='megan', devices=[PhoneDevice{id=63, callerId='Megan', device='SIP/7714', primary=true, monitored=false, extension='7714'}]}

2005.11.01 11:05:22 Asterisk-IM: Processing NewState:UP event channel : SIP/7714-84ad

2005.11.01 11:05:22 Asterisk-IM OnPhoneTask called for user PhoneUser{id=46, username='megan', devices=[PhoneDevice{id=63, callerId='Megan', device='SIP/7714', primary=true, monitored=false, extension='7714'}]}

2005.11.01 11:05:22 Asterisk-IM OnPhoneTask: setting presence to away for PhoneUser{id=46, username='megan', devices=[PhoneDevice{id=63, callerId='Megan', device='SIP/7714', primary=true, monitored=false, extension='7714'}]}

2005.11.01 11:05:46 Asterisk-IM HangupTask called for user PhoneUser{id=46, username='megan', devices=[PhoneDevice{id=63, callerId='Megan', device='SIP/7714', primary=true, monitored=false, extension='7714'}]}

2005.11.01 11:05:46 Asterisk-IM HangupTask: User megan has 2 call sessions, not changing presence

2005.11.01 11:05:46 Asterisk-IM HangupTask called for user PhoneUser{id=46, username='megan', devices=[PhoneDevice{id=63, callerId='Megan', device='SIP/7714', primary=true, monitored=false, extension='7714'}]}

2005.11.01 11:05:52 Asterisk-IM: Processing NewState:UP event channel : SIP/6142-efa4

Environment

None

Activity

Show:
David MacKinnon
December 22, 2005, 12:50 PM

I'm still seeing this issue with Agents... (And as an aside, using Agent/2000 instead of SIP/2517 does not give proper presence support, I'm adding both at the moment, but it's a hack )

Here's a debug log of a call...

2005.12.22 15:46:00 Closing connection that has been idle: org.jivesoftware.wildfire.net.SocketConnection@11c21b socket: Socket[addr=/172.16.4.54,port=2177,localport=5222] session: org.jivesoftware.wildfire.ClientSession@1162ab9 status: 1 address: jabber.bofh.net.au/5e1dc3e4 id: 5e1dc3e4 presence:
<presence type="unavailable"/>
2005.12.22 15:46:00 Closing connection that has been idle: org.jivesoftware.wildfire.net.SocketConnection@dd841 socket: Socket[addr=/172.16.4.54,port=2171,localport=5222] session: org.jivesoftware.wildfire.ClientSession@14005e1 status: -1 address: jabber.bofh.net.au/a606996b id: a606996b presence:
<presence type="unavailable" from="jabber.bofh.net.au/a606996b"/>
2005.12.22 15:46:09 Asterisk-IM: Processing NewState:UP event channel : CAPI/ISDN1/93557844-d id: 1135226765.161
2005.12.22 15:46:09 Asterisk-IM OnPhoneTask: Could not find device/jid mapping for device CAPI/ISDN1/93557844 returning
2005.12.22 15:46:10 Closing connection that has been idle: org.jivesoftware.wildfire.net.SocketConnection@11c21b socket: Socket[addr=/172.16.4.54,port=2177,localport=5222] session: org.jivesoftware.wildfire.ClientSession@1162ab9 status: -1 address: jabber.bofh.net.au/5e1dc3e4 id: 5e1dc3e4 presence:
<presence type="unavailable" from="jabber.bofh.net.au/5e1dc3e4"/>
2005.12.22 15:46:10 Closing connection that has been idle: org.jivesoftware.wildfire.net.SocketConnection@dd841 socket: Socket[addr=/172.16.4.54,port=2171,localport=5222] session: org.jivesoftware.wildfire.ClientSession@14005e1 status: -1 address: jabber.bofh.net.au/a606996b id: a606996b presence:
<presence type="unavailable" from="jabber.bofh.net.au/a606996b"/>
2005.12.22 15:46:17 Asterisk-IM: Processing NewChannel:RINGING event channel : SIP/2507-9244 id: 1135226775.168
2005.12.22 15:46:17 Asterisk-IM: Processing NewChannel:RINGING event channel : SIP/2513-cfbe id: 1135226775.169
2005.12.22 15:46:18 Asterisk-IM RingTask called for user PhoneUser{id=5, username='seoman', devices=[PhoneDevice{id=5, callerId='Simon Hookway', device='Agent/2006', primary=true, monitored=false, extension='2006'}, PhoneDevice{id=11, callerId='Simon', device='SIP/2507', primary=false, monitored=false, extension='2507'}]}
2005.12.22 15:46:18 Asterisk-IM RingTask called for user PhoneUser{id=1, username='david', devices=[PhoneDevice{id=1, callerId='David MacKinnon', device='Agent/2000', primary=true, monitored=false, extension='2000'}, PhoneDevice{id=7, callerId='David', device='SIP/2513', primary=false, monitored=false, extension='2513'}]}
2005.12.22 15:46:18 Asterisk-IM: Processing NewState:UP event channel : SIP/2513-cfbe id: 1135226775.169
2005.12.22 15:46:18 Asterisk-IM: Processing HangupEvent channel : Local/2507@default-be49,1 id: 1135226775.162
2005.12.22 15:46:18 Asterisk-IM: Processing HangupEvent channel : Agent/2006 id: 1135226775.164
2005.12.22 15:46:18 Asterisk-IM: Processing HangupEvent channel : SIP/2507-9244 id: 1135226775.168
2005.12.22 15:46:18 Asterisk-IM: Processing HangupEvent channel : Local/2507@default-be49,2 id: 1135226775.163
2005.12.22 15:46:18 Asterisk-IM: Processing NewState:UP event channel : Local/2513@default-40d1,2 id: 1135226775.166
2005.12.22 15:46:18 Asterisk-IM: Processing HangupEvent channel : Local/2513@default-40d1,1<ZOMBIE> id: 1135226775.169
2005.12.22 15:46:18 Asterisk-IM: Processing HangupEvent channel : Local/2513@default-40d1,2 id: 1135226775.166
2005.12.22 15:46:18 Asterisk-IM OnPhoneTask called for user PhoneUser{id=1, username='david', devices=[PhoneDevice{id=1, callerId='David MacKinnon', device='Agent/2000', primary=true, monitored=false, extension='2000'}, PhoneDevice{id=7, callerId='David', device='SIP/2513', primary=false, monitored=false, extension='2513'}]}
2005.12.22 15:46:18 Asterisk-IM OnPhoneTask: setting presence to away for PhoneUser{id=1, username='david', devices=[PhoneDevice{id=1, callerId='David MacKinnon', device='Agent/2000', primary=true, monitored=false, extension='2000'}, PhoneDevice{id=7, callerId='David', device='SIP/2513', primary=false, monitored=false, extension='2513'}]}
2005.12.22 15:46:19 Asterisk-IM HangupTask called for user PhoneUser{id=5, username='seoman', devices=[PhoneDevice{id=5, callerId='Simon Hookway', device='Agent/2006', primary=true, monitored=false, extension='2006'}, PhoneDevice{id=11, callerId='Simon', device='SIP/2507', primary=false, monitored=false, extension='2507'}]}
2005.12.22 15:46:19 Cannot destroy non-existent CallSession with id: 1135226775.164
2005.12.22 15:46:19 Cannot destroy non-existent CallSession with id: Agent/2006
2005.12.22 15:46:19 Asterisk-IM LinkTask: Initialized call session CallSession{id='1135226775.167', channel='Agent/2000', linkedChannel='CAPI/ISDN1/93557844-d', callerID='null', forwardedExtension='null', forwardedJID=null, dialedJID=null, username='david', isMonitored=false}
2005.12.22 15:46:19 Asterisk-IM HangupTask called for user PhoneUser{id=5, username='seoman', devices=[PhoneDevice{id=5, callerId='Simon Hookway', device='Agent/2006', primary=true, monitored=false, extension='2006'}, PhoneDevice{id=11, callerId='Simon', device='SIP/2507', primary=false, monitored=false, extension='2507'}]}
2005.12.22 15:46:19 Asterisk-IM OnPhoneTask: Could not find device/jid mapping for device Local/2513@default returning
2005.12.22 15:46:20 Asterisk-IM LinkTask: Initialized call session CallSession{id='1135226775.169', channel='SIP/2513-cfbe', linkedChannel='Local/2513@default-40d1,2', callerID='2513', forwardedExtension='null', forwardedJID=null, dialedJID=null, username='david', isMonitored=false}
2005.12.22 15:46:20 Closing connection that has been idle: org.jivesoftware.wildfire.net.SocketConnection@11c21b socket: Socket[addr=/172.16.4.54,port=2177,localport=5222] session: org.jivesoftware.wildfire.ClientSession@1162ab9 status: -1 address: jabber.bofh.net.au/5e1dc3e4 id: 5e1dc3e4 presence:
<presence type="unavailable" from="jabber.bofh.net.au/5e1dc3e4"/>
2005.12.22 15:46:20 Closing connection that has been idle: org.jivesoftware.wildfire.net.SocketConnection@dd841 socket: Socket[addr=/172.16.4.54,port=2171,localport=5222] session: org.jivesoftware.wildfire.ClientSession@14005e1 status: -1 address: jabber.bofh.net.au/a606996b id: a606996b presence:
<presence type="unavailable" from="jabber.bofh.net.au/a606996b"/>
2005.12.22 15:46:22 Asterisk-IM: Processing HangupEvent channel : SIP/2513-cfbe id: 1135226775.165
2005.12.22 15:46:22 Asterisk-IM: Processing HangupEvent channel : Agent/2000 id: 1135226775.167
2005.12.22 15:46:22 Asterisk-IM: Processing HangupEvent channel : CAPI/ISDN1/93557844-d id: 1135226765.161
2005.12.22 15:46:22 Asterisk-IM HangupTask called for user PhoneUser{id=1, username='david', devices=[PhoneDevice{id=1, callerId='David MacKinnon', device='Agent/2000', primary=true, monitored=false, extension='2000'}, PhoneDevice{id=7, callerId='David', device='SIP/2513', primary=false, monitored=false, extension='2513'}]}
2005.12.22 15:46:23 Asterisk-IM HangupTask: User david has 2 call sessions, not restoring presence. Destroying CallSession{id=1135226775.165, channel=SIP/2513-cfbe}
2005.12.22 15:46:23 Cannot destroy non-existent CallSession with id: 1135226775.165
2005.12.22 15:46:23 Asterisk-IM HangupTask: Remaining CallSession CallSession{id='1135226775.169', channel='SIP/2513-cfbe', linkedChannel='Local/2513@default-40d1,2', callerID='2513', forwardedExtension='null', forwardedJID=null, dialedJID=null, username='david', isMonitored=false}
2005.12.22 15:46:23 Asterisk-IM HangupTask: Remaining CallSession CallSession{id='1135226775.167', channel='Agent/2000', linkedChannel='CAPI/ISDN1/93557844-d', callerID='null', forwardedExtension='null', forwardedJID=null, dialedJID=null, username='david', isMonitored=false}
2005.12.22 15:46:23 Asterisk-IM HangupTask called for user PhoneUser{id=1, username='david', devices=[PhoneDevice{id=1, callerId='David MacKinnon', device='Agent/2000', primary=true, monitored=false, extension='2000'}, PhoneDevice{id=7, callerId='David', device='SIP/2513', primary=false, monitored=false, extension='2513'}]}
2005.12.22 15:46:23 Asterisk-IM HangupTask: User david has 2 call sessions, not restoring presence. Destroying CallSession{id=1135226775.167, channel=Agent/2000}
2005.12.22 15:46:23 Asterisk-IM HangupTask: Remaining CallSession CallSession{id='1135226775.169', channel='SIP/2513-cfbe', linkedChannel='Local/2513@default-40d1,2', callerID='2513', forwardedExtension='null', forwardedJID=null, dialedJID=null, username='david', isMonitored=false}
2005.12.22 15:46:23 Cannot destroy non-existent CallSession with id: Agent/2000
2005.12.22 15:46:31 Closing connection that has been idle: org.jivesoftware.wildfire.net.SocketConnection@11c21b socket: Socket[addr=/172.16.4.54,port=2177,localport=5222] session: org.jivesoftware.wildfire.ClientSession@1162ab9 status: -1 address: jabber.bofh.net.au/5e1dc3e4 id: 5e1dc3e4 presence:
<presence type="unavailable" from="jabber.bofh.net.au/5e1dc3e4"/>
2005.12.22 15:46:31 Closing connection that has been idle: org.jivesoftware.wildfire.net.SocketConnection@dd841 socket: Socket[addr=/172.16.4.54,port=2171,localport=5222] session: org.jivesoftware.wildfire.ClientSession@14005e1 status: -1 address: jabber.bofh.net.au/a606996b id: a606996b presence:
<presence type="unavailable" from="jabber.bofh.net.au/a606996b"/>
2005.12.22 15:46:41 Closing connection that has been idle: org.jivesoftware.wildfire.net.SocketConnection@11c21b socket: Socket[addr=/172.16.4.54,port=2177,localport=5222] session: org.jivesoftware.wildfire.ClientSession@1162ab9 status: -1 address: jabber.bofh.net.au/5e1dc3e4 id: 5e1dc3e4 presence:
<presence type="unavailable" from="jabber.bofh.net.au/5e1dc3e4"/>
2005.12.22 15:46:41 Closing connection that has been idle: org.jivesoftware.wildfire.net.SocketConnection@dd841 socket: Socket[addr=/172.16.4.54,port=2171,localport=5222] session: org.jivesoftware.wildfire.ClientSession@14005e1 status: -1 address: jabber.bofh.net.au/a606996b id: a606996b presence:
<presence type="unavailable" from="jabber.bofh.net.au/a606996b"/>

Gaston Dombiak
November 17, 2005, 1:33 PM

1. Fixed case reported in last comment
2. Added recovery logic so that when a user hangs up (i.e. is no longer on the phone) and if his presence is still on the phone then the presence will be modifed to available (logging that the recovery logic took place). If this ever happens then we would still have to fix the root of the problem

Gaston Dombiak
November 17, 2005, 12:00 PM

I finally found a way to reproduce this problem.

1. User1 logs in
2. User1 logs in again from another client
3. User1 starts a conversation (on the phone)
4. User1 logs out from one client
5. User1 hangs up

The rest of the users will still see User1 as on the phone.

Gaston Dombiak
November 16, 2005, 1:13 AM

2005.11.14 11:04:19 Asterisk-IM: Processing NewState:UP event channel : SIP/7813-dda1
2005.11.14 11:04:19 Asterisk-IM OnPhoneTask called for user PhoneUser{id=34, username='dave', devices=[PhoneDevice{id=51, callerId='Dave Hersh', device='SIP/7813', primary=true, monitored=false, extension='7813'}]}
2005.11.14 11:04:19 Asterisk-IM OnPhoneTask: setting presence to away for PhoneUser{id=34, username='dave', devices=[PhoneDevice{id=51, callerId='Dave Hersh', device='SIP/7813', primary=true, monitored=false, extension='7813'}]}
2005.11.14 11:04:19 Asterisk-IM LinkTask: Initialized call session CallSession{id='1131987819.9238', channel='SIP/7813-dda1', linkedChannel='Zap/14-1', callerID='5034641122', forwardedExtension='null', forwardedJID=null, dialedJID=null, username='dave', isMonitored=false}
2005.11.14 11:05:05 Asterisk-IM: Processing HangupEvent channel : SIP/7813-dda1
2005.11.14 11:05:05 Asterisk-IM HangupTask called for user PhoneUser{id=34, username='dave', devices=[PhoneDevice{id=51, callerId='Dave Hersh', device='SIP/7813', primary=true, monitored=false, extension='7813'}]}

2005.11.14 11:55:51 Asterisk-IM: Processing NewState:UP event channel : SIP/7813-c8ef
2005.11.14 11:55:51 Asterisk-IM OnPhoneTask called for user PhoneUser{id=34, username='dave', devices=[PhoneDevice{id=51, callerId='Dave Hersh', device='SIP/7813', primary=true, monitored=false, extension='7813'}]}
2005.11.14 11:55:51 Asterisk-IM OnPhoneTask: setting presence to away for PhoneUser{id=34, username='dave', devices=[PhoneDevice{id=51, callerId='Dave Hersh', device='SIP/7813', primary=true, monitored=false, extension='7813'}]}
2005.11.14 11:55:51 Asterisk-IM LinkTask: Initialized call session CallSession{id='1131990910.9265', channel='SIP/7813-c8ef', linkedChannel='Zap/14-1', callerID='5034641122', forwardedExtension='null', forwardedJID=null, dialedJID=null, username='dave', isMonitored=false}
2005.11.14 11:56:06 Asterisk-IM: Processing HangupEvent channel : SIP/7813-c8ef
2005.11.14 11:56:06 Asterisk-IM HangupTask called for user PhoneUser{id=34, username='dave', devices=[PhoneDevice{id=51, callerId='Dave Hersh', device='SIP/7813', primary=true, monitored=false, extension='7813'}]}

2005.11.14 14:58:46 Asterisk-IM: Processing NewChannel:RINGING event channel : SIP/7813-67fa
2005.11.14 14:58:46 Asterisk-IM RingTask called for user PhoneUser{id=34, username='dave', devices=[PhoneDevice{id=51, callerId='Dave Hersh', device='SIP/7813', primary=true, monitored=false, extension='7813'}]}
2005.11.14 14:58:56 Asterisk-IM: Processing NewState:UP event channel : SIP/7813-67fa
2005.11.14 14:58:56 Asterisk-IM OnPhoneTask called for user PhoneUser{id=34, username='dave', devices=[PhoneDevice{id=51, callerId='Dave Hersh', device='SIP/7813', primary=true, monitored=false, extension='7813'}]}
2005.11.14 14:58:56 Asterisk-IM OnPhoneTask: setting presence to away for PhoneUser{id=34, username='dave', devices=[PhoneDevice{id=51, callerId='Dave Hersh', device='SIP/7813', primary=true, monitored=false, extension='7813'}]}

2005.11.14 14:59:16 Asterisk-IM: Processing NewState:UP event channel : SIP/7813-9f0e
2005.11.14 14:59:16 Asterisk-IM OnPhoneTask called for user PhoneUser{id=34, username='dave', devices=[PhoneDevice{id=51, callerId='Dave Hersh', device='SIP/7813', primary=true, monitored=false, extension='7813'}]}
2005.11.14 14:59:16 Asterisk-IM OnPhoneTask: setting presence to away for PhoneUser{id=34, username='dave', devices=[PhoneDevice{id=51, callerId='Dave Hersh', device='SIP/7813', primary=true, monitored=false, extension='7813'}]}
2005.11.14 14:59:16 Asterisk-IM LinkTask: Initialized call session CallSession{id='1132001954.9359', channel='SIP/7813-9f0e', linkedChannel='SIP/7714-84e5', callerID='7714', forwardedExtension='null', forwardedJID=null, dialedJID=null, username='dave', isMonitored=false}
2005.11.14 14:59:16 Asterisk-IM LinkTask: Initialized call session CallSession{id='1132001954.9360', channel='SIP/7714-84e5', linkedChannel='SIP/7813-9f0e', callerID='"Dave Hersh" ', forwardedExtension='null', forwardedJID=null, dialedJID=null, username='megan', isMonitored=false}
2005.11.14 14:59:18 Asterisk-IM: Processing HangupEvent channel : SIP/7813-67fa
2005.11.14 14:59:18 Asterisk-IM: Processing HangupEvent channel : SIP/7813-9f0e<ZOMBIE>
2005.11.14 14:59:18 Asterisk-IM HangupTask called for user PhoneUser{id=34, username='dave', devices=[PhoneDevice{id=51, callerId='Dave Hersh', device='SIP/7813', primary=true, monitored=false, extension='7813'}]}
2005.11.14 14:59:18 Asterisk-IM HangupTask: User dave has 2 call sessions, not restoring presence. Destroying CallSession{id=1132001926.9358, channel=SIP/7813-67fa}
2005.11.14 14:59:18 Asterisk-IM HangupTask: Remaining CallSession CallSession{id='1132001954.9359', channel='SIP/7813-9f0e', linkedChannel='SIP/7714-84e5', callerID='7714', forwardedExtension='null', forwardedJID=null, dialedJID=null, username='dave', isMonitored=false}
2005.11.14 14:59:18 Asterisk-IM HangupTask called for user PhoneUser{id=34, username='dave', devices=[PhoneDevice{id=51, callerId='Dave Hersh', device='SIP/7813', primary=true, monitored=false, extension='7813'}]}

2005.11.14 15:40:36 OnPhonePacketInterceptor: No queued presences, queuing current presence and setting presence to "Away:On Phone" for:
<presence id="M8x75-169" from="dave@jivesoftware.com/Jive">
<status>Away due to idle.</status>
<show>away</show>
<x xmlns="vcard-temp:x:update">
<photo>b6ab6044aec86b1b9117ab527b4b01ea</photo>
</x>
<x xmlns="jabber:x:avatar">
<hash>b6ab6044aec86b1b9117ab527b4b01ea</hash>
</x>
</presence>
2005.11.14 15:40:36 OnPhonePacketInterceptor: removing old presence from queue for jid dave@jivesoftware.com/Jive
2005.11.14 15:40:36 OnPhonePacketInterceptor: adding presence to queue for jid dave@jivesoftware.com/Jive. Rejecting presence:
<presence id="M8x75-169" from="dave@jivesoftware.com/Jive">
<status>Away due to idle.</status>
<show>away</show>
<x xmlns="vcard-temp:x:update">
<photo>b6ab6044aec86b1b9117ab527b4b01ea</photo>
</x>
<x xmlns="jabber:x:avatar">
<hash>b6ab6044aec86b1b9117ab527b4b01ea</hash>
</x>
</presence>

2005.11.14 16:18:55 Asterisk-IM: Processing NewChannel:RINGING event channel : SIP/7813-c2cf
2005.11.14 16:18:55 Asterisk-IM RingTask called for user PhoneUser{id=34, username='dave', devices=[PhoneDevice{id=51, callerId='Dave Hersh', device='SIP/7813', primary=true, monitored=false, extension='7813'}]}
2005.11.14 16:19:15 Asterisk-IM: Processing HangupEvent channel : SIP/7813-c2cf
2005.11.14 16:19:15 Asterisk-IM HangupTask called for user PhoneUser{id=34, username='dave', devices=[PhoneDevice{id=51, callerId='Dave Hersh', device='SIP/7813', primary=true, monitored=false, extension='7813'}]}
2005.11.14 16:19:15 Asterisk-IM HangupTask: User dave has 2 call sessions, not restoring presence. Destroying CallSession{id=1132006734.9402, channel=SIP/7813-c2cf}
2005.11.14 16:19:15 Asterisk-IM HangupTask: Remaining CallSession CallSession{id='1132001954.9359', channel='SIP/7813-9f0e', linkedChannel='SIP/7714-84e5', callerID='7714', forwardedExtension='null', forwardedJID=null, dialedJID=null, username='dave', isMonitored=false}

2005.11.14 17:56:16 Asterisk-IM: Processing NewChannel:RINGING event channel : SIP/7813-4b26
2005.11.14 17:56:16 Asterisk-IM RingTask called for user PhoneUser{id=34, username='dave', devices=[PhoneDevice{id=51, callerId='Dave Hersh', device='SIP/7813', primary=true, monitored=false, extension='7813'}]}
2005.11.14 17:56:20 Asterisk-IM: Processing NewState:UP event channel : SIP/7813-4b26
2005.11.14 17:56:20 Asterisk-IM OnPhoneTask called for user PhoneUser{id=34, username='dave', devices=[PhoneDevice{id=51, callerId='Dave Hersh', device='SIP/7813', primary=true, monitored=false, extension='7813'}]}
2005.11.14 17:56:20 Asterisk-IM OnPhoneTask: setting presence to away for PhoneUser{id=34, username='dave', devices=[PhoneDevice{id=51, callerId='Dave Hersh', device='SIP/7813', primary=true, monitored=false, extension='7813'}]}
2005.11.14 17:56:20 Asterisk-IM LinkTask: Initialized call session CallSession{id='1132012575.9475', channel='SIP/7813-4b26', linkedChannel='SIP/7714-6007', callerID='"Megan Ross" ', forwardedExtension='null', forwardedJID=null, dialedJID=null, username='dave', isMonitored=false}
2005.11.14 17:56:54 Asterisk-IM HangupTask called for user PhoneUser{id=34, username='dave', devices=[PhoneDevice{id=51, callerId='Dave Hersh', device='SIP/7813', primary=true, monitored=false, extension='7813'}]}
2005.11.14 17:56:54 Asterisk-IM HangupTask: User dave has 2 call sessions, not restoring presence. Destroying CallSession{id=1132012575.9475, channel=SIP/7813-4b26}

2005.11.14 17:57:00 Asterisk-IM OnPhoneTask called for user PhoneUser{id=34, username='dave', devices=[PhoneDevice{id=51, callerId='Dave Hersh', device='SIP/7813', primary=true, monitored=false, extension='7813'}]}
2005.11.14 17:57:00 Asterisk-IM OnPhoneTask: setting presence to away for PhoneUser{id=34, username='dave', devices=[PhoneDevice{id=51, callerId='Dave Hersh', device='SIP/7813', primary=true, monitored=false, extension='7813'}]}

2005.11.14 17:57:11 Asterisk-IM: Processing NewState:UP event channel : SIP/7813-91d7
2005.11.14 17:57:11 Asterisk-IM OnPhoneTask called for user PhoneUser{id=34, username='dave', devices=[PhoneDevice{id=51, callerId='Dave Hersh', device='SIP/7813', primary=true, monitored=false, extension='7813'}]}
2005.11.14 17:57:11 Asterisk-IM OnPhoneTask: setting presence to away for PhoneUser{id=34, username='dave', devices=[PhoneDevice{id=51, callerId='Dave Hersh', device='SIP/7813', primary=true, monitored=false, extension='7813'}]}
2005.11.14 17:57:11 Asterisk-IM LinkTask: Initialized call session CallSession{id='1132012628.9477', channel='SIP/7813-91d7', linkedChannel='SIP/7714-cbd0', callerID='7714', forwardedExtension='null', forwardedJID=null, dialedJID=null, username='dave', isMonitored=false}
2005.11.14 17:57:11 Asterisk-IM LinkTask: Initialized call session CallSession{id='1132012628.9478', channel='SIP/7714-cbd0', linkedChannel='SIP/7813-91d7', callerID='"Dave Hersh" ', forwardedExtension='null', forwardedJID=null, dialedJID=null, username='megan', isMonitored=false}
2005.11.14 17:57:19 Asterisk-IM: Processing HangupEvent channel : SIP/7813-10b8
2005.11.14 17:57:19 Asterisk-IM HangupTask called for user PhoneUser{id=34, username='dave', devices=[PhoneDevice{id=51, callerId='Dave Hersh', device='SIP/7813', primary=true, monitored=false, extension='7813'}]}
2005.11.14 17:57:19 Asterisk-IM HangupTask: User dave has 3 call sessions, not restoring presence. Destroying CallSession{id=1132012620.9476, channel=SIP/7813-10b8}
2005.11.14 17:57:19 Asterisk-IM HangupTask: Remaining CallSession CallSession{id='1132001954.9359', channel='SIP/7813-9f0e', linkedChannel='SIP/7714-84e5', callerID='7714', forwardedExtension='null', forwardedJID=null, dialedJID=null, username='dave', isMonitored=false}
2005.11.14 17:57:19 Asterisk-IM HangupTask: Remaining CallSession CallSession{id='1132012628.9477', channel='SIP/7813-91d7', linkedChannel='SIP/7714-cbd0', callerID='7714', forwardedExtension='null', forwardedJID=null, dialedJID=null, username='dave', isMonitored=false}
2005.11.14 17:57:25 Asterisk-IM: Processing HangupEvent channel : SIP/7714-cbd0
2005.11.14 17:57:25 Asterisk-IM: Processing HangupEvent channel : SIP/7813-91d7
2005.11.14 17:57:25 Asterisk-IM HangupTask called for user PhoneUser{id=46, username='megan', devices=[PhoneDevice{id=63, callerId='Megan', device='SIP/7714', primary=true, monitored=false, extension='7714'}]}
2005.11.14 17:57:25 Asterisk-IM HangupTask called for user PhoneUser{id=34, username='dave', devices=[PhoneDevice{id=51, callerId='Dave Hersh', device='SIP/7813', primary=true, monitored=false, extension='7813'}]}
2005.11.14 17:57:25 Asterisk-IM HangupTask: User dave has 2 call sessions, not restoring presence. Destroying CallSession{id=1132012628.9477, channel=SIP/7813-91d7}
2005.11.14 17:57:25 Asterisk-IM HangupTask: Remaining CallSession CallSession{id='1132001954.9359', channel='SIP/7813-9f0e', linkedChannel='SIP/7714-84e5', callerID='7714', forwardedExtension='null', forwardedJID=null, dialedJID=null, username='dave', isMonitored=false}
2005.11.14 17:57:31 Asterisk-IM: Processing NewState:UP event channel : SIP/7813-ca5a
2005.11.14 17:57:31 Asterisk-IM OnPhoneTask called for user PhoneUser{id=34, username='dave', devices=[PhoneDevice{id=51, callerId='Dave Hersh', device='SIP/7813', primary=true, monitored=false, extension='7813'}]}
2005.11.14 17:57:31 Asterisk-IM OnPhoneTask: setting presence to away for PhoneUser{id=34, username='dave', devices=[PhoneDevice{id=51, callerId='Dave Hersh', device='SIP/7813', primary=true, monitored=false, extension='7813'}]}
2005.11.14 17:57:42 Asterisk-IM: Processing HangupEvent channel : SIP/7813-ca5a
2005.11.14 17:57:42 Asterisk-IM HangupTask called for user PhoneUser{id=34, username='dave', devices=[PhoneDevice{id=51, callerId='Dave Hersh', device='SIP/7813', primary=true, monitored=false, extension='7813'}]}
2005.11.14 17:57:42 Asterisk-IM HangupTask: User dave has 2 call sessions, not restoring presence. Destroying CallSession{id=1132012651.9479, channel=SIP/7813-ca5a}
2005.11.14 17:57:42 Asterisk-IM HangupTask: Remaining CallSession CallSession{id='1132001954.9359', channel='SIP/7813-9f0e', linkedChannel='SIP/7714-84e5', callerID='7714', forwardedExtension='null', forwardedJID=null, dialedJID=null, username='dave', isMonitored=false}
2005.11.14 17:57:47 Asterisk-IM: Processing NewState:UP event channel : SIP/7813-b3f3
2005.11.14 17:57:47 Asterisk-IM OnPhoneTask called for user PhoneUser{id=34, username='dave', devices=[PhoneDevice{id=51, callerId='Dave Hersh', device='SIP/7813', primary=true, monitored=false, extension='7813'}]}
2005.11.14 17:57:47 Asterisk-IM OnPhoneTask: setting presence to away for PhoneUser{id=34, username='dave', devices=[PhoneDevice{id=51, callerId='Dave Hersh', device='SIP/7813', primary=true, monitored=false, extension='7813'}]}
2005.11.14 17:57:52 Asterisk-IM: Processing NewChannel:RINGING event channel : SIP/7714-dce6
2005.11.14 17:57:52 Asterisk-IM RingTask called for user PhoneUser{id=46, username='megan', devices=[PhoneDevice{id=63, callerId='Megan', device='SIP/7714', primary=true, monitored=false, extension='7714'}]}
2005.11.14 17:57:54 Asterisk-IM: Processing NewState:UP event channel : SIP/7714-dce6
2005.11.14 17:57:54 Asterisk-IM OnPhoneTask called for user PhoneUser{id=46, username='megan', devices=[PhoneDevice{id=63, callerId='Megan', device='SIP/7714', primary=true, monitored=false, extension='7714'}]}
2005.11.14 17:57:54 Asterisk-IM OnPhoneTask: setting presence to away for PhoneUser{id=46, username='megan', devices=[PhoneDevice{id=63, callerId='Megan', device='SIP/7714', primary=true, monitored=false, extension='7714'}]}
2005.11.14 17:57:54 Asterisk-IM: Processing NewState:UP event channel : SIP/7813-ed7d
2005.11.14 17:57:54 Asterisk-IM OnPhoneTask called for user PhoneUser{id=34, username='dave', devices=[PhoneDevice{id=51, callerId='Dave Hersh', device='SIP/7813', primary=true, monitored=false, extension='7813'}]}
2005.11.14 17:57:54 Asterisk-IM OnPhoneTask: setting presence to away for PhoneUser{id=34, username='dave', devices=[PhoneDevice{id=51, callerId='Dave Hersh', device='SIP/7813', primary=true, monitored=false, extension='7813'}]}
2005.11.14 17:57:54 Asterisk-IM LinkTask: Initialized call session CallSession{id='1132012671.9481', channel='SIP/7813-ed7d', linkedChannel='SIP/7714-dce6', callerID='7714', forwardedExtension='null', forwardedJID=null, dialedJID=null, username='dave', isMonitored=false}
2005.11.14 17:57:54 Asterisk-IM LinkTask: Initialized call session CallSession{id='1132012671.9482', channel='SIP/7714-dce6', linkedChannel='SIP/7813-ed7d', callerID='"Dave Hersh" ', forwardedExtension='null', forwardedJID=null, dialedJID=null, username='megan', isMonitored=false}
2005.11.14 17:58:05 Asterisk-IM: Processing HangupEvent channel : SIP/7813-b3f3
2005.11.14 17:58:05 Asterisk-IM HangupTask called for user PhoneUser{id=34, username='dave', devices=[PhoneDevice{id=51, callerId='Dave Hersh', device='SIP/7813', primary=true, monitored=false, extension='7813'}]}
2005.11.14 17:58:05 Asterisk-IM HangupTask: User dave has 3 call sessions, not restoring presence. Destroying CallSession{id=1132012667.9480, channel=SIP/7813-b3f3}
2005.11.14 17:58:05 Asterisk-IM HangupTask: Remaining CallSession CallSession{id='1132001954.9359', channel='SIP/7813-9f0e', linkedChannel='SIP/7714-84e5', callerID='7714', forwardedExtension='null', forwardedJID=null, dialedJID=null, username='dave', isMonitored=false}
2005.11.14 17:58:05 Asterisk-IM HangupTask: Remaining CallSession CallSession{id='1132012671.9481', channel='SIP/7813-ed7d', linkedChannel='SIP/7714-dce6', callerID='7714', forwardedExtension='null', forwardedJID=null, dialedJID=null, username='dave', isMonitored=false}

2005.11.14 17:58:42 Asterisk-IM: Processing NewState:UP event channel : SIP/7813-58a8
2005.11.14 17:58:42 Asterisk-IM OnPhoneTask called for user PhoneUser{id=34, username='dave', devices=[PhoneDevice{id=51, callerId='Dave Hersh', device='SIP/7813', primary=true, monitored=false, extension='7813'}]}
2005.11.14 17:58:42 Asterisk-IM OnPhoneTask: setting presence to away for PhoneUser{id=34, username='dave', devices=[PhoneDevice{id=51, callerId='Dave Hersh', device='SIP/7813', primary=true, monitored=false, extension='7813'}]}
2005.11.14 17:58:44 Asterisk-IM: Processing HangupEvent channel : SIP/7813-58a8<ZOMBIE>
2005.11.14 17:58:44 Asterisk-IM: Processing HangupEvent channel : SIP/7813-ed7d
2005.11.14 17:58:44 Asterisk-IM HangupTask called for user PhoneUser{id=34, username='dave', devices=[PhoneDevice{id=51, callerId='Dave Hersh', device='SIP/7813', primary=true, monitored=false, extension='7813'}]}
2005.11.14 17:58:44 Asterisk-IM HangupTask: User dave has 3 call sessions, not restoring presence. Destroying CallSession{id=1132012671.9482, channel=SIP/7813-58a8<ZOMBIE>}
2005.11.14 17:58:44 Asterisk-IM HangupTask: Remaining CallSession CallSession{id='1132001954.9359', channel='SIP/7813-9f0e', linkedChannel='SIP/7714-84e5', callerID='7714', forwardedExtension='null', forwardedJID=null, dialedJID=null, username='dave', isMonitored=false}
2005.11.14 17:58:44 Asterisk-IM HangupTask: Remaining CallSession CallSession{id='1132012671.9481', channel='SIP/7813-ed7d', linkedChannel='SIP/7714-dce6', callerID='7714', forwardedExtension='null', forwardedJID=null, dialedJID=null, username='dave', isMonitored=false}
2005.11.14 17:58:44 Asterisk-IM HangupTask: Remaining CallSession CallSession{id='1132012722.9483', channel='null', linkedChannel='null', callerID='null', forwardedExtension='null', forwardedJID=null, dialedJID=null, username='dave', isMonitored=false}
2005.11.14 17:58:44 Asterisk-IM HangupTask called for user PhoneUser{id=34, username='dave', devices=[PhoneDevice{id=51, callerId='Dave Hersh', device='SIP/7813', primary=true, monitored=false, extension='7813'}]}
2005.11.14 17:58:44 Asterisk-IM HangupTask: User dave has 3 call sessions, not restoring presence. Destroying CallSession{id=1132012671.9481, channel=SIP/7813-ed7d}
2005.11.14 17:58:44 Asterisk-IM HangupTask: Remaining CallSession CallSession{id='1132001954.9359', channel='SIP/7813-9f0e', linkedChannel='SIP/7714-84e5', callerID='7714', forwardedExtension='null', forwardedJID=null, dialedJID=null, username='dave', isMonitored=false}
2005.11.14 17:58:44 Asterisk-IM HangupTask: Remaining CallSession CallSession{id='1132012722.9483', channel='null', linkedChannel='null', callerID='null', forwardedExtension='null', forwardedJID=null, dialedJID=null, username='dave', isMonitored=false}

2005.11.14 17:59:02 Asterisk-IM: Processing NewState:UP event channel : SIP/7813-d715
2005.11.14 17:59:02 Asterisk-IM OnPhoneTask called for user PhoneUser{id=34, username='dave', devices=[PhoneDevice{id=51, callerId='Dave Hersh', device='SIP/7813', primary=true, monitored=false, extension='7813'}]}
2005.11.14 17:59:02 Asterisk-IM OnPhoneTask: setting presence to away for PhoneUser{id=34, username='dave', devices=[PhoneDevice{id=51, callerId='Dave Hersh', device='SIP/7813', primary=true, monitored=false, extension='7813'}]}
2005.11.14 17:59:02 Asterisk-IM LinkTask: Initialized call session CallSession{id='1132012734.9484', channel='SIP/7813-d715', linkedChannel='SIP/7714-6fea', callerID='7714', forwardedExtension='null', forwardedJID=null, dialedJID=null, username='dave', isMonitored=false}
2005.11.14 17:59:02 Asterisk-IM LinkTask: Initialized call session CallSession{id='1132012734.9485', channel='SIP/7714-6fea', linkedChannel='SIP/7813-d715', callerID='"Dave Hersh" ', forwardedExtension='null', forwardedJID=null, dialedJID=null, username='megan', isMonitored=false}
2005.11.14 17:59:06 Asterisk-IM: Processing NewState:UP event channel : SIP/7813-be01
2005.11.14 17:59:06 Asterisk-IM OnPhoneTask called for user PhoneUser{id=34, username='dave', devices=[PhoneDevice{id=51, callerId='Dave Hersh', device='SIP/7813', primary=true, monitored=false, extension='7813'}]}
2005.11.14 17:59:06 Asterisk-IM OnPhoneTask: setting presence to away for PhoneUser{id=34, username='dave', devices=[PhoneDevice{id=51, callerId='Dave Hersh', device='SIP/7813', primary=true, monitored=false, extension='7813'}]}
2005.11.14 17:59:07 Logging off derek@jivesoftware.com/Jive on org.jivesoftware.messenger.net.SocketConnection@15f7161 socket: Socket[addr=/67.139.233.26,port=4253,localport=5222] session: org.jivesoftware.messenger.ClientSession@aca220 status: 3 address: derek@jivesoftware.com/Jive id: 96690366 presence:
<presence id="PModp-6" from="derek@jivesoftware.com/Jive">
<status>Online</status>
</presence>
2005.11.14 17:59:07 Asterisk-IM: Processing HangupEvent channel : SIP/7813-be01<ZOMBIE>
2005.11.14 17:59:07 Asterisk-IM: Processing HangupEvent channel : SIP/7813-d715
2005.11.14 17:59:07 Asterisk-IM HangupTask called for user PhoneUser{id=34, username='dave', devices=[PhoneDevice{id=51, callerId='Dave Hersh', device='SIP/7813', primary=true, monitored=false, extension='7813'}]}
2005.11.14 17:59:07 Asterisk-IM HangupTask: User dave has 3 call sessions, not restoring presence. Destroying CallSession{id=1132012734.9485, channel=SIP/7813-be01<ZOMBIE>}
2005.11.14 17:59:07 Asterisk-IM HangupTask: Remaining CallSession CallSession{id='1132001954.9359', channel='SIP/7813-9f0e', linkedChannel='SIP/7714-84e5', callerID='7714', forwardedExtension='null', forwardedJID=null, dialedJID=null, username='dave', isMonitored=false}
2005.11.14 17:59:07 Asterisk-IM HangupTask: Remaining CallSession CallSession{id='1132012734.9484', channel='SIP/7813-d715', linkedChannel='SIP/7714-6fea', callerID='7714', forwardedExtension='null', forwardedJID=null, dialedJID=null, username='dave', isMonitored=false}
2005.11.14 17:59:07 Asterisk-IM HangupTask: Remaining CallSession CallSession{id='1132012746.9486', channel='null', linkedChannel='null', callerID='null', forwardedExtension='null', forwardedJID=null, dialedJID=null, username='dave', isMonitored=false}
2005.11.14 17:59:07 Asterisk-IM HangupTask called for user PhoneUser{id=34, username='dave', devices=[PhoneDevice{id=51, callerId='Dave Hersh', device='SIP/7813', primary=true, monitored=false, extension='7813'}]}
2005.11.14 17:59:07 Asterisk-IM HangupTask: User dave has 3 call sessions, not restoring presence. Destroying CallSession{id=1132012734.9484, channel=SIP/7813-d715}
2005.11.14 17:59:07 Asterisk-IM HangupTask: Remaining CallSession CallSession{id='1132001954.9359', channel='SIP/7813-9f0e', linkedChannel='SIP/7714-84e5', callerID='7714', forwardedExtension='null', forwardedJID=null, dialedJID=null, username='dave', isMonitored=false}
2005.11.14 17:59:07 Asterisk-IM HangupTask: Remaining CallSession CallSession{id='1132012746.9486', channel='null', linkedChannel='null', callerID='null', forwardedExtension='null', forwardedJID=null, dialedJID=null, username='dave', isMonitored=false}

Gaston Dombiak
November 10, 2005, 2:04 PM

The problem seems to be that CallSessions are being generated and never destroyed. So AsteriskEventHandler.HangupTask#run() will print something like:

2005.11.09 15:09:46 Asterisk-IM HangupTask: User john has 2 call sessions, not changing presence

and the original presence will never be restored.

Fixed

Assignee

Gaston Dombiak

Reporter

Gaston Dombiak