onNewAsteriskChannel event after HangupEvent

Asterisk Asterisk Support
1

Hi. I got a problem.

When I test multi calls about over 100 calls on asterisk 1.4,
onNewAsteriskChannel event occured after HangupEvent.

I developed outbound service with FastAGI Java.

Please take a look at time log.

  • DialEvent. ([color=#0000FF]SIP/innodial-0000022c[/color])
    [2013-12-28 [color=#FF0000]03:46:04,076[/color] DEBUG org.asteriskjava.manager.internal.ManagerConnectionImpl] - Dispatching event:
    org.asteriskjava.manager.event.[color=#0000FF]DialEvent[/color][dateReceived=‘Sat Dec 28 03:46:04 PST 2013’,privilege=‘call,all’,subevent=‘Begin’,callerid=‘7146601001’,dialstatus=null,
    sequencenumber=null,destuniqueid=‘1388231164.1937’,srcuniqueid=‘1388231163.1933’,
    destination=’[color=#0000FF]SIP/innodial-000022c[/color]’,
    dialstring=null,timestamp=null,calleridname=null,uniqueid=‘1388231163.1933’,server=null,src=‘Local/s@outbound-message-5466,2’,calleridnum=‘7146601001’,channel=‘Local/s@outbound-message-5466,2’,systemHashcode=215643037]

  • NewCallerIdEvent
    [2013-12-28 03:46:04,077 DEBUG org.asteriskjava.manager.internal.ManagerConnectionImpl] - Dispatching event:
    org.asteriskjava.manager.event.[color=#0000FF]NewCallerIdEvent[/color][dateReceived=‘Sat Dec 28 03:46:04 PST 2013’,privilege=‘call,all’,callerid=‘s’,sequencenumber=null,calleridname=null,
    timestamp=null,uniqueid=‘1388231164.1937’,cidcallingpres=‘0’,cidcallingprestxt=‘Presentation Allowed, Not Screened’,server=null,calleridnum=‘s’,
    channel=’[color=#0000FF]SIP/innodial-0000022c[/color]’,systemHashcode=1507610370]

…

- HanupEvent(I set timeout 25s)
[2013-12-28 [color=#FF0000]03:46:29,407[/color] DEBUG org.asteriskjava.manager.internal.ManagerConnectionImpl] - Dispatching event:
org.asteriskjava.manager.event.[color=#0000FF]HangupEvent[/color][dateReceived=‘Sat Dec 28 03:46:29 PST 2013’,privilege=‘call,all’,
[color=#0000FF]causetxt=‘Normal Clearing’,callerid=null,cause=‘16’,[/color]
sequencenumber=null,calleridname=null,timestamp=null,uniqueid=‘1388231164.1937’,
server=null,calleridnum=null,channel=’[color=#0000FF]SIP/innodial-0000022c[/color]’,systemHashcode=1872342874]

- CdrEvent
[2013-12-28 03:46:29,415 DEBUG org.asteriskjava.manager.internal.ManagerConnectionImpl] - Dispatching event:
org.asteriskjava.manager.event.[color=#0000FF]CdrEvent[/color][dateReceived=‘Sat Dec 28 03:46:29 PST 2013’,privilege=‘call,all’,endtime=‘2013-12-28 03:46:29’,destinationchannel=’[color=#0000FF]SIP/innodial-0000022c[/color]’,userfield=null,sequencenumber=null,starttimeasdate=‘Sat Dec 28 03:46:03 PST 2013’,timestamp=null,billableseconds=‘0’,endtimeasdate=‘Sat Dec 28 03:46:29 PST 2013’,accountcode=null,lastdata=‘SIP/14159441104@innodial’,answertimeasdate=null,src=‘7146601001’,disposition=‘NO ANSWER’,callerid=‘7146601001’,starttime=‘2013-12-28 03:46:03’,answertime=null,destination=‘s’,uniqueid=‘1388231163.1933’,lastapplication=‘Dial’,duration=‘26’,amaflags=‘DOCUMENTATION’,server=null,destinationcontext=‘outbound-message’,channel=‘Local/s@outbound-message-5466,2’,systemHashcode=582012639]

- Adding channel(The call(SIP/innodial-0000022c) was already hangup)
[2013-12-28 [color=#FF0000]03:46:29,605[/color] INFO org.asteriskjava.live.internal.ChannelManager] -
[color=#0000FF]Adding channel SIP/innodial-0000022c/color

- onNewAsteriskChannel(this is from AsteriskServerListener)
[2013-12-28 [color=#FF0000]03:46:29,665[/color] DEBUG com.trumpia.listener.VoiceAsteriskServerListener] - [color=#0000FF]onNewAsteriskChannel [/color]event
[2013-12-28 03:46:29,665 DEBUG com.trumpia.listener.VoiceAsteriskServerListener] - AsteriskChannel[id=‘1388231164.1937’,
name=’[color=#0000FF]SIP/innodial-0000022c[/color]’,
callerId=’’,state=‘DOWN’,account=‘null’,dateOfCreation=Sat Dec 28 03:46:04 PST 2013,dialedChannel=null,dialingChannel=null,linkedChannel=null]

[color=#008000]- At onNewAsteriskChannel event occured, I command “core show channel SIP/innodial-0000022c” , it returned “SIP/innodial-0000022c is not a known channel”.
[/color]

------------------------------------------- In normal case(Test 1 call)
- DialEvent([color=#FF0000]SIP/innodial-000005ad[/color])
[2013-12-28 [color=#FF0000]19:53:39[/color],926 DEBUG org.asteriskjava.manager.internal.ManagerConnectionImpl] - Dispatching event:
org.asteriskjava.manager.event.[color=#0000FF]DialEvent[/color][dateReceived=‘Sat Dec 28 19:53:39 PST 2013’,privilege=‘call,all’,subevent=‘Begin’,callerid=‘7146601001’,dialstatus=null,sequencenumber=null,destuniqueid=‘1388289219.4692’,srcuniqueid=‘1388289219.4691’,
destination=’[color=#0000FF]SIP/innodial-000005ad[/color]’,
dialstring=null,timestamp=null,calleridname=null,uniqueid=‘1388289219.4691’,server=null,src=‘Local/s@outbound-message-2e46,2’,calleridnum=‘7146601001’,channel=‘Local/s@outbound-message-2e46,2’,systemHashcode=630299550]

…

- Adding channel
[2013-12-28 [color=#FF0000]19:53:39[/color],964 INFO org.asteriskjava.live.internal.ChannelManager] - Adding [color=#0000FF]channel SIP/innodial-000005ad/color

- onNewAsteriskChannel(this is from AsteriskServerListener)
[2013-12-28 [color=#FF0000]19:53:40,017[/color] DEBUG com.trumpia.listener.VoiceAsteriskServerListener] - [color=#0000FF]onNewAsteriskChannel event[/color]

  • At onNewAsteriskChannel event occured, I command “core show channel SIP/innodial-000005ad” , it returned Sip channel information.

Is this performance issue?
What should I do?
please help me~

Happy new year~!! :smiley:

2

Looks like a problem with your JAVA class library. In any case Asterisk 1.4 is several years beyond end of life.

The library seems to be recreating its mirror of the channel as a result of the CDR which was produced when the channel was hungup.

3

Thanks for your reply and I’m really appreciate that you answered everytime I ask something.

[quote=“david55”]
The library seems to be recreating its mirror of the channel as a result of the CDR which was produced when the channel was hungup.[/quote]

I don’t know what this means.
I couldn’t find any problem in CDR event log.
Could you please give me more details?

To outbound service,(for playing recored voice)

  1. originate to local channel (Local/xxx, 1 and Loca/xxx, 2 created)
  2. local channel invoke AgiScript.
  3. dial out to sip channel in the AgiScript.(Sip/xxxx created)

So there are three channels created for 1 call.
(Local/xxxx,1 | Local/xxxx, 2 | Sip/xxxxx)

What I’m wondering is that…
In normal case, After DialEvent, asterisk add a channel( SIP/innodial-000005ad )(onNewAsteriskChannel event occured) immediately.
But in weired case, After DialEvent and HangupEvent occured, asterisk add a channel(SIP/innodial-0000022c)(onNewAsteriskChannel event occured)

Is this performance issue on only asterisk 1.4?
This issue occured sometimes during multi calls over 100~ calls. not everytime.

I use the lastest version of org.asteriskjava 1.0.0.M3.

4

one thing weired is why hangup event occured?
the call was not dialed out because there is no channel to dial out. Just DialEvent was occured.

I think it should check timeout(25s) after a channel is created to dial out(onNewAsteriskChannel). NOT DialEvent.

5

You have provided the output from a Java class library, not from Asterisk. The problem appears to be in that Java class library, as the event you are complaining about seems to be an inferred event, not an event that Asterisk itself has generated.

6

This is my VoiceAsteriskServerListener java class.
VoiceAsteriskServerListener implements AsteriskServerListener that asterisk provide.
I just log AsteriskChannel in onNewAsteriskChannel()

import org.asteriskjava.live.AsteriskChannel;
import org.asteriskjava.live.AsteriskQueueEntry;
import org.asteriskjava.live.AsteriskServerListener;
import org.asteriskjava.live.MeetMeUser;
import org.asteriskjava.live.internal.AsteriskAgentImpl;

public class VoiceAsteriskServerListener implements AsteriskServerListener, PropertyChangeListener {

    @Override
    public void onNewAsteriskChannel(final AsteriskChannel channel) {
        JFLogger.logDebug(getClass(), "-------------------------------------------------------------------------------------- onNewAsteriskChannel > " + channel.getName());
    }

    @Override
    public void onNewMeetMeUser(final MeetMeUser user) {
        JFLogger.logDebug(getClass(), "-------------------------------------------------------------------------------------- onNewMeetMeUser");
    }

    @Override
    public void onNewAgent(final AsteriskAgentImpl agent) {
        JFLogger.logDebug(getClass(), "-------------------------------------------------------------------------------------- onNewAgent");
    }

    @Override
    public void onNewQueueEntry(final AsteriskQueueEntry entry) {
        JFLogger.logDebug(getClass(), "-------------------------------------------------------------------------------------- onNewQueueEntry");
    }

    @Override
    public void propertyChange(final PropertyChangeEvent evt) {
        JFLogger.logDebug(getClass(), "-------------------------------------------------------------------------------------- propertyChange");
    }
}

When adding a new channel, onNewAsteriskChannel() is invoked by asterisk server(I guess).

and I can guess after this happen the below

[2013-12-28 03:46:29,605 INFO org.asteriskjava.live.internal.ChannelManager] - Adding channel SIP/innodial-0000022c(1388231164.1937)
onNewAsteriskChannel() is invoked.

Anyway I can say the logs all that I provided is from asterisk server or manager.

7

Your class library is org.asteriskjava.live For support, see the first item in asterisk-java.org/development/faq.html

8

Ok. I see.
Thanks David :smiley:
Have a nice day!!