Inbound Call Routes

I have been struggling with a strange problem with inbound routes.

A little background:
I have a 4-port digium (only using 2 right now)
One line is plugged into a POTS fax line, the other to a POTS voice line.

I have an inbound route setup to send to a IAX extension (hylafax)
I have another inbound route setup to send to a time condition, that goes to an IVR…

If i place a call to the voice POTS line, the IVR picks up fine. If i hang up and dial back immediately (less than ~45 secs), the line picks up and makes a “fax-like” tone for a few seconds, then the IVR kicks in and seems to be working fine.

Here an excerpt of the logs for 2 calls placed back to back:

[code:1]
Jul 27 15:39:19 DEBUG[7543] chan_zap.c: Requested indication 3 on channel Zap/4-1
Jul 27 15:39:19 DEBUG[7543] pbx.c: Expression result is ‘1’
Jul 27 15:39:19 DEBUG[7543] pbx.c: Function result is ‘s’
Jul 27 15:39:19 DEBUG[7543] pbx.c: Expression result is ‘1’
Jul 27 15:39:19 DEBUG[7543] pbx.c: Function result is ‘4’
Jul 27 15:39:19 DEBUG[7543] app_macro.c: Executed application: Noop
Jul 27 15:39:19 DEBUG[7543] app_macro.c: Executed application: Set
Jul 27 15:39:19 DEBUG[7543] app_macro.c: Executed application: Goto
Jul 27 15:39:19 DEBUG[7543] pbx.c: Function result is ‘NO ANSWER’
Jul 27 15:39:19 DEBUG[7543] pbx.c: Expression result is ‘0’
Jul 27 15:39:19 DEBUG[7543] pbx.c: Not taking any branch
Jul 27 15:39:19 DEBUG[7543] chan_zap.c: Took Zap/4-1 off hook
Jul 27 15:39:19 DEBUG[7543] chan_zap.c: Enabled echo cancellation on channel 4
Jul 27 15:39:19 DEBUG[7543] chan_zap.c: Engaged echo training on channel 4
Jul 27 15:39:20 DEBUG[7543] channel.c: Scheduling timer at 160 sample intervals
Jul 27 15:39:23 DEBUG[7543] chan_zap.c: Exception on 17, channel 4
Jul 27 15:39:23 DEBUG[7543] chan_zap.c: Got event On hook(1) on channel 4 (index 0)
Jul 27 15:39:23 DEBUG[7543] chan_zap.c: disabled echo cancellation on channel 4
Jul 27 15:39:23 DEBUG[7543] channel.c: Scheduling timer at 0 sample intervals
Jul 27 15:39:23 DEBUG[7543] chan_zap.c: Hangup: channel: 4 index = 0, normal = 17, callwait = -1, thirdcall = -1
Jul 27 15:39:23 DEBUG[7543] chan_zap.c: disabled echo cancellation on channel 4
Jul 27 15:39:23 DEBUG[7543] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/4-1
Jul 27 15:39:23 DEBUG[7543] chan_zap.c: Updated conferencing on 4, with 0 conference users
Jul 27 15:39:23 DEBUG[7543] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Jul 27 15:39:23 DEBUG[7543] cdr_addon_mysql.c: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid) VALUES (‘2007-07-27 15:39:19’,’“INVOSTAR” <5612281371>’,‘5612281371’,‘s’,‘ivr-2’, ‘Zap/4-1’,’’,‘BackGround’,‘custom/FirstGreeting’,4,4,‘ANSWERED’,3,’’,‘1185565158.33’)
Jul 27 15:39:45 WARNING[7547] chan_zap.c: CallerID returned with error on channel ‘Zap/4-1’
Jul 27 15:39:45 DEBUG[7547] chan_zap.c: Requested indication 3 on channel Zap/4-1
Jul 27 15:39:45 DEBUG[7547] pbx.c: Expression result is ‘1’
Jul 27 15:39:45 DEBUG[7547] pbx.c: Function result is ‘s’
Jul 27 15:39:45 DEBUG[7547] pbx.c: Expression result is ‘1’
Jul 27 15:39:45 DEBUG[7547] pbx.c: Function result is ‘4’
Jul 27 15:39:45 DEBUG[7547] app_macro.c: Executed application: Noop
Jul 27 15:39:45 DEBUG[7547] app_macro.c: Executed application: Set
Jul 27 15:39:45 DEBUG[7547] app_macro.c: Executed application: Goto
Jul 27 15:39:45 DEBUG[7547] pbx.c: Function result is ‘NO ANSWER’
Jul 27 15:39:45 DEBUG[7547] pbx.c: Expression result is ‘0’
Jul 27 15:39:45 DEBUG[7547] pbx.c: Not taking any branch
Jul 27 15:39:45 DEBUG[7547] chan_zap.c: Took Zap/4-1 off hook
Jul 27 15:39:45 DEBUG[7547] chan_zap.c: Enabled echo cancellation on channel 4
Jul 27 15:39:45 DEBUG[7547] chan_zap.c: Engaged echo training on channel 4
Jul 27 15:39:46 DEBUG[7547] channel.c: Scheduling timer at 160 sample intervals
Jul 27 15:39:49 NOTICE[5173] chan_iax2.c: Restricting registration for peer ‘1100’ to 60 seconds (requested 300)
Jul 27 15:39:49 DEBUG[5173] chan_iax2.c: Peer lastms 4, historicms 4, maxms 2000
Jul 27 15:39:49 NOTICE[5173] chan_iax2.c: Restricting registration for peer ‘1100’ to 60 seconds (requested 300)
Jul 27 15:39:49 DEBUG[5173] chan_iax2.c: Peer lastms 2, historicms 2, maxms 2000
Jul 27 15:39:53 DEBUG[7547] channel.c: Scheduling timer at 58 sample intervals
Jul 27 15:39:53 DEBUG[7547] channel.c: Scheduling timer at 0 sample intervals
Jul 27 15:39:53 DEBUG[7547] channel.c: Scheduling timer at 0 sample intervals
Jul 27 15:39:53 DEBUG[7547] chan_zap.c: Exception on 17, channel 4
Jul 27 15:39:53 DEBUG[7547] chan_zap.c: Got event On hook(1) on channel 4 (index 0)
Jul 27 15:39:53 DEBUG[7547] chan_zap.c: disabled echo cancellation on channel 4
Jul 27 15:39:53 DEBUG[7547] chan_zap.c: Hangup: channel: 4 index = 0, normal = 17, callwait = -1, thirdcall = -1
Jul 27 15:39:53 DEBUG[7547] chan_zap.c: disabled echo cancellation on channel 4
Jul 27 15:39:53 DEBUG[7547] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/4-1
Jul 27 15:39:53 DEBUG[7547] chan_zap.c: Updated conferencing on 4, with 0 conference users
Jul 27 15:39:53 DEBUG[7547] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Jul 27 15:39:53 DEBUG[7547] cdr_addon_mysql.c: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid) VALUES (‘2007-07-27 15:39:45’,’’,’’,‘s’,‘ivr-2’, ‘Zap/4-1’,’’,‘WaitExten’,’’,8,8,‘ANSWERED’,3,’’,‘1185565177.34’)
Jul 27 15:39:54 DEBUG[5173] chan_iax2.c: Peer lastms 1, historicms 1, maxms 2000
Jul 27 15:39:54 DEBUG[5173] chan_iax2.c: Peer lastms 1, historicms 1, maxms 2000
[/code:1]

Also, here is the overview from the call log. Something that I find interesting is that the CLID and Source are blank on the second call…

[code:1]

  1.  2007-07-27 15:39:45 	Zap/4-1... 			s 	ANSWERED 	00:08
    
  2.  2007-07-27 15:39:19 	Zap/4-1... 	5612281371 	"INVOSTAR" <5612281371> 	s 	ANSWERED 	00:04
    

[/code:1]

Any suggestions are welcome.

/Stu

I’m having problem with my inbound routes, I have TDM400P with 4 FXO and one line is plugged into a POTS voice line.
I tried to call my POTS direct number line that directly connected to my freePBX but i got this info:
– Starting simple switch on ‘Zap/1-1’
– Executing [[email protected]:1] Playback(“Zap/1-1”, “vm-goodbye”) in new stack
– <Zap/1-1> Playing ‘vm-goodbye’ (language ‘en’)
– Executing [[email protected]:2] Macro(“Zap/1-1”, “hangupcall”) in new stack
– Executing [[email protected]:1] ResetCDR(“Zap/1-1”, “w”) in new stack
– Executing [[email protected]:2] NoCDR(“Zap/1-1”, “”) in new stack
– Executing [[email protected]:3] GotoIf(“Zap/1-1”, “1?skiprg”) in new stack
– Goto (macro-hangupcall,s,6)
– Executing [[email protected]:6] GotoIf(“Zap/1-1”, “1?skipblkvm”) in new stack
– Goto (macro-hangupcall,s,9)
– Executing [[email protected]:9] GotoIf(“Zap/1-1”, “1?theend”) in new stack
– Goto (macro-hangupcall,s,11)
– Executing [[email protected]:11] Hangup(“Zap/1-1”, “”) in new stack
== Spawn extension (macro-hangupcall, s, 11) exited non-zero on ‘Zap/1-1’ in macro ‘hangupcall’
== Spawn extension (macro-hangupcall, s, 11) exited non-zero on ‘Zap/1-1’
– Hungup ‘Zap/1-1’

My Inbound is not working, my outbound is properly working and i can call ordinary phones in my area and cell numbers.

Question:
Is there any configurations that I missed?

I’m using a different POTS direct line from my hardphone