Incoming fax to fax machine

have a Xeon 3.2Ghz Server with 2gb RAM located at a datacentre with a dedicated 10mb link to the internet. I have several trunks setup for inbound and outbound calls (mostly SIP but 1 IAX)

This is connected to a prodigy firewall then to the internet.

At the remote sites I have connected a Siemans C460 IP Dect phone and a Linksys PAP2T.

I have configured line 2 of the PAP2T for faxing, and am using G711A as the only protocol on this line.

I have configured the extension for G711A only as well.

I have several incoming numbers some of which are provided by Sipgate the other numbers are provided by Magrathea. With Magrathea you provision the number direct to an asterisk extension eg

[email protected]
where xx.xx.xx.xx = the public ip address of the datacentre.

If I dial the incoming number using voice the extension rings and I can talk to the person at the extension.

If I send a fax to the same number the fax machine answers but the fax always fails.

At first when I was looking at the log files I noticed that there was an error ‘Unknown RTP codec 100 received’ which is something to do with receiving a T38 fax on a T30 line. I found a fix for this which I have done. I no longer get that error but I still can not receive a fax to the Magrathea number.

If I send fax to my sipgate number and I create an incoming rule to send it to the same extension as the Magrathea number the fax is received perfectly every time.

Can any one help me. I have posted the log files for a successful received fax via sipgate and a non successful one from Magrathea:-

Thanks in advance

Derek


***************************************************** Successful Fax:-********


Mar 18 19:06:04 DEBUG[3003] chan_sip.c: Setting NAT on RTP to 524288
Mar 18 19:06:04 DEBUG[3003] chan_sip.c: Checking SIP call limits for device 1434207
Mar 18 19:06:04 DEBUG[3003] chan_sip.c: build_route: Record-Route hop:
Mar 18 19:06:04 DEBUG[3003] chan_sip.c: build_route: Record-Route hop:
Mar 18 19:06:04 VERBOSE[11367] logger.c: – Executing Set(“SIP/1434207-08bed770”, “FROM_DID=1434207”) in new stack
Mar 18 19:06:04 VERBOSE[11367] logger.c: – Executing Gosub(“SIP/1434207-08bed770”, “app-blacklist-check|s|1”) in new stack
Mar 18 19:06:04 VERBOSE[11367] logger.c: – Executing LookupBlacklist(“SIP/1434207-08bed770”, “”) in new stack
Mar 18 19:06:04 DEBUG[11367] db.c: Unable to find key ‘unbekannt’ in family 'blacklist’
Mar 18 19:06:04 DEBUG[11367] db.c: Unable to find key ‘unknown’ in family 'blacklist’
Mar 18 19:06:04 DEBUG[11367] pbx.c: Expression result is '0’
Mar 18 19:06:04 VERBOSE[11367] logger.c: – Executing GotoIf(“SIP/1434207-08bed770”, “0?blacklisted”) in new stack
Mar 18 19:06:04 DEBUG[11367] pbx.c: Not taking any branch
Mar 18 19:06:04 VERBOSE[11367] logger.c: – Executing Return(“SIP/1434207-08bed770”, “”) in new stack
Mar 18 19:06:04 VERBOSE[11367] logger.c: – Executing Set(“SIP/1434207-08bed770”, “FAX_RX=3082”) in new stack
Mar 18 19:06:04 VERBOSE[11367] logger.c: – Executing Goto(“SIP/1434207-08bed770”, “ext-local|3082|1”) in new stack
Mar 18 19:06:04 VERBOSE[11367] logger.c: – Goto (ext-local,3082,1)
Mar 18 19:06:04 VERBOSE[11367] logger.c: – Executing Macro(“SIP/1434207-08bed770”, “exten-vm|novm|3082”) in new stack
Mar 18 19:06:04 VERBOSE[11367] logger.c: – Executing Macro(“SIP/1434207-08bed770”, “user-callerid”) in new stack
Mar 18 19:06:04 DEBUG[11367] pbx.c: Function result is 'unknown’
Mar 18 19:06:04 DEBUG[11367] pbx.c: Function result is 'unbekannt’
Mar 18 19:06:04 VERBOSE[11367] logger.c: – Executing NoOp(“SIP/1434207-08bed770”, “user-callerid: unknown unbekannt”) in new stack
Mar 18 19:06:04 DEBUG[11367] pbx.c: Expression result is '0’
Mar 18 19:06:04 VERBOSE[11367] logger.c: – Executing GotoIf(“SIP/1434207-08bed770”, “0?report”) in new stack
Mar 18 19:06:04 DEBUG[11367] pbx.c: Not taking any branch
Mar 18 19:06:04 DEBUG[11367] pbx.c: Expression result is '0’
Mar 18 19:06:04 VERBOSE[11367] logger.c: – Executing GotoIf(“SIP/1434207-08bed770”, “0?start”) in new stack
Mar 18 19:06:04 DEBUG[11367] pbx.c: Not taking any branch
Mar 18 19:06:04 DEBUG[11367] pbx.c: Function result is 'unbekannt’
Mar 18 19:06:04 VERBOSE[11367] logger.c: – Executing Set(“SIP/1434207-08bed770”, “REALCALLERIDNUM=unbekannt”) in new stack
Mar 18 19:06:04 VERBOSE[11367] logger.c: – Executing NoOp(“SIP/1434207-08bed770”, “REALCALLERIDNUM is unbekannt”) in new stack
Mar 18 19:06:04 DEBUG[11367] db.c: Unable to find key ‘unbekannt/user’ in family 'DEVICE’
Mar 18 19:06:04 DEBUG[11367] func_db.c: DB: DEVICE/unbekannt/user not found in database.
Mar 18 19:06:04 DEBUG[11367] pbx.c: Function result is ''
Mar 18 19:06:04 VERBOSE[11367] logger.c: – Executing Set(“SIP/1434207-08bed770”, “AMPUSER=”) in new stack
Mar 18 19:06:04 DEBUG[11367] db.c: Unable to find key ‘/cidname’ in family 'AMPUSER’
Mar 18 19:06:04 DEBUG[11367] func_db.c: DB: AMPUSER//cidname not found in database.
Mar 18 19:06:04 DEBUG[11367] pbx.c: Function result is ''
Mar 18 19:06:04 VERBOSE[11367] logger.c: – Executing Set(“SIP/1434207-08bed770”, “AMPUSERCIDNAME=”) in new stack
Mar 18 19:06:04 DEBUG[11367] pbx.c: Expression result is '1’
Mar 18 19:06:04 VERBOSE[11367] logger.c: – Executing GotoIf(“SIP/1434207-08bed770”, “1?report”) in new stack
Mar 18 19:06:04 VERBOSE[11367] logger.c: – Goto (macro-user-callerid,s,11)
Mar 18 19:06:04 VERBOSE[11367] logger.c: – Executing NoOp(“SIP/1434207-08bed770”, “TTL: ARG1: novm”) in new stack
Mar 18 19:06:04 DEBUG[11367] pbx.c: Expression result is '0’
Mar 18 19:06:04 VERBOSE[11367] logger.c: – Executing GotoIf(“SIP/1434207-08bed770”, “0?continue”) in new stack
Mar 18 19:06:04 DEBUG[11367] pbx.c: Not taking any branch
Mar 18 19:06:04 DEBUG[11367] pbx.c: Expression result is '1’
Mar 18 19:06:04 DEBUG[11367] pbx.c: Expression result is '-1’
Mar 18 19:06:04 DEBUG[11367] pbx.c: Function result is '64’
Mar 18 19:06:04 VERBOSE[11367] logger.c: – Executing Set(“SIP/1434207-08bed770”, “_TTL=64”) in new stack
Mar 18 19:06:04 DEBUG[11367] pbx.c: Expression result is '1’
Mar 18 19:06:04 VERBOSE[11367] logger.c: – Executing GotoIf(“SIP/1434207-08bed770”, “1?continue”) in new stack
Mar 18 19:06:04 VERBOSE[11367] logger.c: – Goto (macro-user-callerid,s,21)
Mar 18 19:06:04 DEBUG[11367] pbx.c: Function result is '“unknown” '
Mar 18 19:06:04 VERBOSE[11367] logger.c: – Executing NoOp(“SIP/1434207-08bed770”, "Using CallerID “unknown” ") in new stack
Mar 18 19:06:04 VERBOSE[11367] logger.c: – Executing Set(“SIP/1434207-08bed770”, “FROMCONTEXT=exten-vm”) in new stack
Mar 18 19:06:04 VERBOSE[11367] logger.c: – Executing Set(“SIP/1434207-08bed770”, “VMBOX=novm”) in new stack
Mar 18 19:06:04 VERBOSE[11367] logger.c: – Executing Set(“SIP/1434207-08bed770”, “EXTTOCALL=3082”) in new stack
Mar 18 19:06:04 DEBUG[11367] db.c: Unable to find key ‘3082’ in family 'CFU’
Mar 18 19:06:04 DEBUG[11367] func_db.c: DB: CFU/3082 not found in database.
Mar 18 19:06:04 DEBUG[11367] pbx.c: Function result is ''
Mar 18 19:06:04 VERBOSE[11367] logger.c: – Executing Set(“SIP/1434207-08bed770”, “CFUEXT=”) in new stack
Mar 18 19:06:04 DEBUG[11367] db.c: Unable to find key ‘3082’ in family 'CFB’
Mar 18 19:06:04 DEBUG[11367] func_db.c: DB: CFB/3082 not found in database.
Mar 18 19:06:04 DEBUG[11367] pbx.c: Function result is ''
Mar 18 19:06:04 VERBOSE[11367] logger.c: – Executing Set(“SIP/1434207-08bed770”, “CFBEXT=”) in new stack
Mar 18 19:06:04 DEBUG[11367] pbx.c: Expression result is '0’
Mar 18 19:06:04 DEBUG[11367] pbx.c: Expression result is '0’
Mar 18 19:06:04 DEBUG[11367] pbx.c: Expression result is '0’
Mar 18 19:06:04 DEBUG[11367] pbx.c: Function result is ''
Mar 18 19:06:04 VERBOSE[11367] logger.c: – Executing Set(“SIP/1434207-08bed770”, “RT=”) in new stack
Mar 18 19:06:04 VERBOSE[11367] logger.c: – Executing Macro(“SIP/1434207-08bed770”, “record-enable|3082|IN”) in new stack
Mar 18 19:06:04 DEBUG[11367] pbx.c: Function result is '0’
Mar 18 19:06:04 DEBUG[11367] pbx.c: Expression result is '0’
Mar 18 19:06:04 VERBOSE[11367] logger.c: – Executing GotoIf(“SIP/1434207-08bed770”, “0?2:4”) in new stack
Mar 18 19:06:04 VERBOSE[11367] logger.c: – Goto (macro-record-enable,s,4)
Mar 18 19:06:04 VERBOSE[11367] logger.c: – Executing DeadAGI(“SIP/1434207-08bed770”, “recordingcheck|20070318-190604|1174244764.82”) in new stack
Mar 18 19:06:04 VERBOSE[11367] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
Mar 18 19:06:05 VERBOSE[11367] logger.c: recordingcheck|20070318-190604|1174244764.82: Inbound recording not enabled
Mar 18 19:06:05 VERBOSE[11367] logger.c: – AGI Script recordingcheck completed, returning 0
Mar 18 19:06:05 VERBOSE[11367] logger.c: – Executing NoOp(“SIP/1434207-08bed770”, “No recording needed”) in new stack
Mar 18 19:06:05 VERBOSE[11367] logger.c: – Executing Macro(“SIP/1434207-08bed770”, “dial||tr|3082”) in new stack
Mar 18 19:06:05 VERBOSE[11367] logger.c: – Executing DeadAGI(“SIP/1434207-08bed770”, “dialparties.agi”) in new stack
Mar 18 19:06:05 VERBOSE[11367] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
Mar 18 19:06:05 VERBOSE[11367] logger.c: dialparties.agi: Starting New Dialparties.agi
Mar 18 19:06:05 VERBOSE[11367] logger.c: dialparties.agi: priority is 1
Mar 18 19:06:05 VERBOSE[11367] logger.c: dialparties.agi: Caller ID name is ‘unknown’ number is 'unbekannt’
Mar 18 19:06:05 VERBOSE[11367] logger.c: dialparties.agi: Methodology of ring is 'none’
Mar 18 19:06:05 VERBOSE[11367] logger.c: > dialparties.agi: USE_CONFIRMATION: 'FALSE’
Mar 18 19:06:05 VERBOSE[11367] logger.c: > dialparties.agi: RINGGROUP_INDEX: ''
Mar 18 19:06:05 VERBOSE[11367] logger.c: – dialparties.agi: Added extension 3082 to extension map
Mar 18 19:06:05 DEBUG[11367] db.c: Unable to find key ‘3082’ in family 'CF’
Mar 18 19:06:05 VERBOSE[11367] logger.c: – dialparties.agi: Extension 3082 cf is disabled
Mar 18 19:06:05 DEBUG[11367] db.c: Unable to find key ‘3082’ in family 'DND’
Mar 18 19:06:05 VERBOSE[11367] logger.c: – dialparties.agi: Extension 3082 do not disturb is disabled
Mar 18 19:06:05 DEBUG[11367] db.c: Unable to find key ‘3082’ in family 'CFB’
Mar 18 19:06:05 DEBUG[11367] db.c: Unable to find key ‘3082’ in family 'CFU’
Mar 18 19:06:05 VERBOSE[11367] logger.c: > dialparties.agi: extnum: 3082
Mar 18 19:06:05 VERBOSE[11367] logger.c: > dialparties.agi: exthascw: 1
Mar 18 19:06:05 VERBOSE[11367] logger.c: > dialparties.agi: exthascfb: 0
Mar 18 19:06:05 VERBOSE[11367] logger.c: > dialparties.agi: extcfb:
Mar 18 19:06:05 VERBOSE[11367] logger.c: > dialparties.agi: exthascfu: 0
Mar 18 19:06:05 VERBOSE[11367] logger.c: > dialparties.agi: extcfu:
Mar 18 19:06:05 DEBUG[11367] db.c: Unable to find key ‘3082’ in family 'CALLTRACE’
Mar 18 19:06:05 VERBOSE[11367] logger.c: – dialparties.agi: DbDel CALLTRACE/3082 - Caller ID is not defined
Mar 18 19:06:05 VERBOSE[11367] logger.c: – AGI Script dialparties.agi completed, returning 0
Mar 18 19:06:05 VERBOSE[11367] logger.c: – Executing Dial(“SIP/1434207-08bed770”, “SIP/3082||tr”) in new stack
Mar 18 19:06:05 DEBUG[11367] chan_sip.c: Setting NAT on RTP to 524288
Mar 18 19:06:05 DEBUG[11367] chan_sip.c: Outgoing Call for 3082
Mar 18 19:06:05 VERBOSE[11367] logger.c: – Called 3082
Mar 18 19:06:05 DEBUG[3003] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on ‘[email protected]’ Request 102: Found
Mar 18 19:06:05 DEBUG[3003] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on ‘[email protected]’ Request 102: Found
Mar 18 19:06:05 VERBOSE[11367] logger.c: – SIP/3082-08bf0660 is ringing
Mar 18 19:06:11 DEBUG[3003] chan_sip.c: Acked pending invite 102
Mar 18 19:06:11 DEBUG[3003] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Mar 18 19:06:11 DEBUG[3003] chan_sip.c: Oooh, we need to change our formats since our peer supports only 0x8 (alaw) and not 0x4 (ulaw)
Mar 18 19:06:11 DEBUG[3003] chan_sip.c: build_route: Contact hop: MS Fax Line
Mar 18 19:06:11 VERBOSE[11367] logger.c: – SIP/3082-08bf0660 answered SIP/1434207-08bed770
Mar 18 19:06:11 DEBUG[3003] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Response 102: Match Found
Mar 18 19:06:11 DEBUG[11367] chan_sip.c: Oooh, format changed to 8
Mar 18 19:06:21 DEBUG[3004] chan_iax2.c: Peer lastms 9, historicms 9, maxms 2000
Mar 18 19:06:21 DEBUG[3003] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Mar 18 19:06:22 DEBUG[3003] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Mar 18 19:06:22 DEBUG[3004] chan_iax2.c: Peer lastms 31, historicms 31, maxms 2000
Mar 18 19:06:23 DEBUG[3003] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Mar 18 19:06:23 DEBUG[3003] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Mar 18 19:06:23 DEBUG[3003] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Mar 18 19:06:23 DEBUG[3003] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Mar 18 19:06:27 DEBUG[11256] manager.c: Manager received command 'Command’
Mar 18 19:06:27 DEBUG[11256] manager.c: Manager received command 'Command’
Mar 18 19:06:27 DEBUG[11256] manager.c: Manager received command 'Command’
Mar 18 19:06:35 DEBUG[3003] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Mar 18 19:07:07 DEBUG[3003] chan_sip.c: Scheduled a registration timeout for sipgate.co.uk id #317246
Mar 18 19:07:07 DEBUG[3003] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 130: Match Found
Mar 18 19:07:07 DEBUG[3003] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 131: Match Found
Mar 18 19:07:07 DEBUG[3003] chan_sip.c: Registration successful
Mar 18 19:07:07 DEBUG[3003] chan_sip.c: Cancelling timeout 317246
Mar 18 19:07:10 DEBUG[3003] chan_sip.c: Scheduled a registration timeout for sip.voipdiscount.com id #317251
Mar 18 19:07:10 DEBUG[3003] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on ‘[email protected]’ Request 124: Found
Mar 18 19:07:10 DEBUG[3003] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 124: Match Found
Mar 18 19:07:10 DEBUG[3003] chan_sip.c: Registration successful
Mar 18 19:07:10 DEBUG[3003] chan_sip.c: Cancelling timeout 317251
Mar 18 19:07:17 DEBUG[11367] channel.c: Didn’t get a frame from channel: SIP/1434207-08bed770
Mar 18 19:07:17 DEBUG[11367] channel.c: Bridge stops bridging channels SIP/1434207-08bed770 and SIP/3082-08bf0660
Mar 18 19:07:17 DEBUG[11367] chan_sip.c: update_call_counter(3082) - decrement call limit counter
Mar 18 19:07:17 DEBUG[11367] app_dial.c: Exiting with DIALSTATUS=ANSWER.
Mar 18 19:07:17 VERBOSE[11367] logger.c: == Spawn extension (macro-dial, s, 10) exited non-zero on ‘SIP/1434207-08bed770’ in macro 'dial’
Mar 18 19:07:17 VERBOSE[11367] logger.c: == Spawn extension (macro-dial, s, 10) exited non-zero on ‘SIP/1434207-08bed770’ in macro ‘exten-vm’
Mar 18 19:07:17 VERBOSE[11367] logger.c: == Spawn extension (macro-dial, s, 10) exited non-zero on ‘SIP/1434207-08bed770’
Mar 18 19:07:17 VERBOSE[11367] logger.c: – Executing Macro(“SIP/1434207-08bed770”, “hangupcall”) in new stack
Mar 18 19:07:17 VERBOSE[11367] logger.c: – Executing ResetCDR(“SIP/1434207-08bed770”, “w”) in new stack
Mar 18 19:07:17 DEBUG[11367] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Mar 18 19:07:17 DEBUG[11367] 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) VALUES (‘2007-03-18 19:06:04’,’“unknown” ‘,‘unbekannt’,‘3082’,‘ext-local’, ‘SIP/1434207-08bed770’,‘SIP/3082-08bf0660’,‘ResetCDR’,‘w’,73,66,‘ANSWERED’,3,’’)
Mar 18 19:07:17 VERBOSE[11367] logger.c: – Executing NoCDR(“SIP/1434207-08bed770”, “”) in new stack
Mar 18 19:07:17 NOTICE[11367] cdr.c: CDR on channel ‘SIP/1434207-08bed770’ not posted
Mar 18 19:07:17 NOTICE[11367] cdr.c: CDR on channel ‘SIP/1434207-08bed770’ lacks end
Mar 18 19:07:17 DEBUG[11367] pbx.c: Expression result is '1’
Mar 18 19:07:17 VERBOSE[11367] logger.c: – Executing GotoIf(“SIP/1434207-08bed770”, “1?skiprg”) in new stack
Mar 18 19:07:17 VERBOSE[11367] logger.c: – Goto (macro-hangupcall,s,6)
Mar 18 19:07:17 DEBUG[11367] pbx.c: Expression result is '1’
Mar 18 19:07:17 VERBOSE[11367] logger.c: – Executing GotoIf(“SIP/1434207-08bed770”, “1?theend”) in new stack
Mar 18 19:07:17 VERBOSE[11367] logger.c: – Goto (macro-hangupcall,s,9)
Mar 18 19:07:17 VERBOSE[11367] logger.c: – Executing Wait(“SIP/1434207-08bed770”, “5”) in new stack
Mar 18 19:07:17 VERBOSE[11367] logger.c: == Spawn extension (macro-hangupcall, s, 9) exited non-zero on ‘SIP/1434207-08bed770’ in macro 'hangupcall’
Mar 18 19:07:17 VERBOSE[11367] logger.c: == Spawn extension (macro-hangupcall, s, 9) exited non-zero on 'SIP/1434207-08bed770’
Mar 18 19:07:17 DEBUG[11367] chan_sip.c: update_call_counter(1434207) - decrement call limit counter
Mar 18 19:07:17 DEBUG[3003] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 103: Match Found


************************************************** UNSuccessful Fax:-********


Mar 18 19:17:40 DEBUG[3003] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 130: Match Found
Mar 18 19:17:40 DEBUG[3003] chan_sip.c: Registration successful
Mar 18 19:17:40 DEBUG[3003] chan_sip.c: Cancelling timeout 317588
Mar 18 19:17:43 DEBUG[3003] chan_sip.c: Checking SIP call limits for device
Mar 18 19:17:43 DEBUG[3003] chan_sip.c: build_route: Record-Route hop:
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Executing NoOp(“SIP/213.166.5.133-08bf0660”, “Received incoming SIP connection from unknown peer to 3082”) in new stack
Mar 18 19:17:43 DEBUG[11424] pbx.c: Expression result is '0’
Mar 18 19:17:43 DEBUG[11424] pbx.c: Function result is '3082’
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Executing Set(“SIP/213.166.5.133-08bf0660”, “DID=3082”) in new stack
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Executing Goto(“SIP/213.166.5.133-08bf0660”, “s|1”) in new stack
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Goto (from-sip-external,s,1)
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Executing Ringing(“SIP/213.166.5.133-08bf0660”, “”) in new stack
Mar 18 19:17:43 DEBUG[11424] pbx.c: Expression result is '1’
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Executing GotoIf(“SIP/213.166.5.133-08bf0660”, “1?from-trunk|3082|1”) in new stack
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Goto (from-trunk,3082,1)
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Executing Set(“SIP/213.166.5.133-08bf0660”, “FROM_DID=3082”) in new stack
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Executing Gosub(“SIP/213.166.5.133-08bf0660”, “app-blacklist-check|s|1”) in new stack
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Executing LookupBlacklist(“SIP/213.166.5.133-08bf0660”, “”) in new stack
Mar 18 19:17:43 DEBUG[11424] db.c: Unable to find key ‘unknown’ in family 'blacklist’
Mar 18 19:17:43 DEBUG[11424] pbx.c: Expression result is '0’
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Executing GotoIf(“SIP/213.166.5.133-08bf0660”, “0?blacklisted”) in new stack
Mar 18 19:17:43 DEBUG[11424] pbx.c: Not taking any branch
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Executing Return(“SIP/213.166.5.133-08bf0660”, “”) in new stack
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Executing Goto(“SIP/213.166.5.133-08bf0660”, “ext-local|3082|1”) in new stack
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Goto (ext-local,3082,1)
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Executing Macro(“SIP/213.166.5.133-08bf0660”, “exten-vm|novm|3082”) in new stack
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Executing Macro(“SIP/213.166.5.133-08bf0660”, “user-callerid”) in new stack
Mar 18 19:17:43 DEBUG[11424] pbx.c: Function result is 'unknown’
Mar 18 19:17:43 DEBUG[11424] pbx.c: Function result is ''
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Executing NoOp(“SIP/213.166.5.133-08bf0660”, "user-callerid: unknown ") in new stack
Mar 18 19:17:43 DEBUG[11424] pbx.c: Expression result is '0’
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Executing GotoIf(“SIP/213.166.5.133-08bf0660”, “0?report”) in new stack
Mar 18 19:17:43 DEBUG[11424] pbx.c: Not taking any branch
Mar 18 19:17:43 DEBUG[11424] pbx.c: Expression result is '0’
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Executing GotoIf(“SIP/213.166.5.133-08bf0660”, “0?start”) in new stack
Mar 18 19:17:43 DEBUG[11424] pbx.c: Not taking any branch
Mar 18 19:17:43 DEBUG[11424] pbx.c: Function result is ''
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Executing Set(“SIP/213.166.5.133-08bf0660”, “REALCALLERIDNUM=”) in new stack
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Executing NoOp(“SIP/213.166.5.133-08bf0660”, "REALCALLERIDNUM is ") in new stack
Mar 18 19:17:43 DEBUG[11424] db.c: Unable to find key ‘/user’ in family 'DEVICE’
Mar 18 19:17:43 DEBUG[11424] func_db.c: DB: DEVICE//user not found in database.
Mar 18 19:17:43 DEBUG[11424] pbx.c: Function result is ''
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Executing Set(“SIP/213.166.5.133-08bf0660”, “AMPUSER=”) in new stack
Mar 18 19:17:43 DEBUG[11424] db.c: Unable to find key ‘/cidname’ in family 'AMPUSER’
Mar 18 19:17:43 DEBUG[11424] func_db.c: DB: AMPUSER//cidname not found in database.
Mar 18 19:17:43 DEBUG[11424] pbx.c: Function result is ''
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Executing Set(“SIP/213.166.5.133-08bf0660”, “AMPUSERCIDNAME=”) in new stack
Mar 18 19:17:43 DEBUG[11424] pbx.c: Expression result is '1’
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Executing GotoIf(“SIP/213.166.5.133-08bf0660”, “1?report”) in new stack
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Goto (macro-user-callerid,s,11)
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Executing NoOp(“SIP/213.166.5.133-08bf0660”, “TTL: ARG1: novm”) in new stack
Mar 18 19:17:43 DEBUG[11424] pbx.c: Expression result is '0’
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Executing GotoIf(“SIP/213.166.5.133-08bf0660”, “0?continue”) in new stack
Mar 18 19:17:43 DEBUG[11424] pbx.c: Not taking any branch
Mar 18 19:17:43 DEBUG[11424] pbx.c: Expression result is '1’
Mar 18 19:17:43 DEBUG[11424] pbx.c: Expression result is '-1’
Mar 18 19:17:43 DEBUG[11424] pbx.c: Function result is '64’
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Executing Set(“SIP/213.166.5.133-08bf0660”, “_TTL=64”) in new stack
Mar 18 19:17:43 DEBUG[11424] pbx.c: Expression result is '1’
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Executing GotoIf(“SIP/213.166.5.133-08bf0660”, “1?continue”) in new stack
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Goto (macro-user-callerid,s,21)
Mar 18 19:17:43 DEBUG[11424] pbx.c: Function result is '“unknown” <>'
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Executing NoOp(“SIP/213.166.5.133-08bf0660”, “Using CallerID “unknown” <>”) in new stack
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Executing Set(“SIP/213.166.5.133-08bf0660”, “FROMCONTEXT=exten-vm”) in new stack
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Executing Set(“SIP/213.166.5.133-08bf0660”, “VMBOX=novm”) in new stack
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Executing Set(“SIP/213.166.5.133-08bf0660”, “EXTTOCALL=3082”) in new stack
Mar 18 19:17:43 DEBUG[11424] db.c: Unable to find key ‘3082’ in family 'CFU’
Mar 18 19:17:43 DEBUG[11424] func_db.c: DB: CFU/3082 not found in database.
Mar 18 19:17:43 DEBUG[11424] pbx.c: Function result is ''
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Executing Set(“SIP/213.166.5.133-08bf0660”, “CFUEXT=”) in new stack
Mar 18 19:17:43 DEBUG[11424] db.c: Unable to find key ‘3082’ in family 'CFB’
Mar 18 19:17:43 DEBUG[11424] func_db.c: DB: CFB/3082 not found in database.
Mar 18 19:17:43 DEBUG[11424] pbx.c: Function result is ''
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Executing Set(“SIP/213.166.5.133-08bf0660”, “CFBEXT=”) in new stack
Mar 18 19:17:43 DEBUG[11424] pbx.c: Expression result is '0’
Mar 18 19:17:43 DEBUG[11424] pbx.c: Expression result is '0’
Mar 18 19:17:43 DEBUG[11424] pbx.c: Expression result is '0’
Mar 18 19:17:43 DEBUG[11424] pbx.c: Function result is ''
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Executing Set(“SIP/213.166.5.133-08bf0660”, “RT=”) in new stack
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Executing Macro(“SIP/213.166.5.133-08bf0660”, “record-enable|3082|IN”) in new stack
Mar 18 19:17:43 DEBUG[11424] pbx.c: Function result is '0’
Mar 18 19:17:43 DEBUG[11424] pbx.c: Expression result is '0’
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Executing GotoIf(“SIP/213.166.5.133-08bf0660”, “0?2:4”) in new stack
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Goto (macro-record-enable,s,4)
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Executing DeadAGI(“SIP/213.166.5.133-08bf0660”, “recordingcheck|20070318-191743|1174245463.84”) in new stack
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
Mar 18 19:17:43 VERBOSE[11424] logger.c: recordingcheck|20070318-191743|1174245463.84: Inbound recording not enabled
Mar 18 19:17:43 VERBOSE[11424] logger.c: – AGI Script recordingcheck completed, returning 0
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Executing NoOp(“SIP/213.166.5.133-08bf0660”, “No recording needed”) in new stack
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Executing Macro(“SIP/213.166.5.133-08bf0660”, “dial||tr|3082”) in new stack
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Executing DeadAGI(“SIP/213.166.5.133-08bf0660”, “dialparties.agi”) in new stack
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
Mar 18 19:17:43 VERBOSE[11424] logger.c: dialparties.agi: Starting New Dialparties.agi
Mar 18 19:17:43 VERBOSE[11424] logger.c: dialparties.agi: priority is 1
Mar 18 19:17:43 VERBOSE[11424] logger.c: dialparties.agi: Caller ID name is ‘unknown’ number is 'unknown’
Mar 18 19:17:43 VERBOSE[11424] logger.c: dialparties.agi: Methodology of ring is 'none’
Mar 18 19:17:43 VERBOSE[11424] logger.c: > dialparties.agi: USE_CONFIRMATION: 'FALSE’
Mar 18 19:17:43 VERBOSE[11424] logger.c: > dialparties.agi: RINGGROUP_INDEX: ''
Mar 18 19:17:43 VERBOSE[11424] logger.c: – dialparties.agi: Added extension 3082 to extension map
Mar 18 19:17:43 DEBUG[11424] db.c: Unable to find key ‘3082’ in family 'CF’
Mar 18 19:17:43 VERBOSE[11424] logger.c: – dialparties.agi: Extension 3082 cf is disabled
Mar 18 19:17:43 DEBUG[11424] db.c: Unable to find key ‘3082’ in family 'DND’
Mar 18 19:17:43 VERBOSE[11424] logger.c: – dialparties.agi: Extension 3082 do not disturb is disabled
Mar 18 19:17:43 DEBUG[11424] db.c: Unable to find key ‘3082’ in family 'CFB’
Mar 18 19:17:43 DEBUG[11424] db.c: Unable to find key ‘3082’ in family 'CFU’
Mar 18 19:17:43 VERBOSE[11424] logger.c: > dialparties.agi: extnum: 3082
Mar 18 19:17:43 VERBOSE[11424] logger.c: > dialparties.agi: exthascw: 1
Mar 18 19:17:43 VERBOSE[11424] logger.c: > dialparties.agi: exthascfb: 0
Mar 18 19:17:43 VERBOSE[11424] logger.c: > dialparties.agi: extcfb:
Mar 18 19:17:43 VERBOSE[11424] logger.c: > dialparties.agi: exthascfu: 0
Mar 18 19:17:43 VERBOSE[11424] logger.c: > dialparties.agi: extcfu:
Mar 18 19:17:43 DEBUG[11424] db.c: Unable to find key ‘3082’ in family 'CALLTRACE’
Mar 18 19:17:43 VERBOSE[11424] logger.c: – dialparties.agi: DbDel CALLTRACE/3082 - Caller ID is not defined
Mar 18 19:17:43 VERBOSE[11424] logger.c: – AGI Script dialparties.agi completed, returning 0
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Executing Dial(“SIP/213.166.5.133-08bf0660”, “SIP/3082||tr”) in new stack
Mar 18 19:17:43 DEBUG[11424] chan_sip.c: Setting NAT on RTP to 524288
Mar 18 19:17:43 DEBUG[11424] chan_sip.c: Outgoing Call for 3082
Mar 18 19:17:43 VERBOSE[11424] logger.c: – Called 3082
Mar 18 19:17:43 DEBUG[3003] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on ‘[email protected]’ Request 102: Found
Mar 18 19:17:43 DEBUG[3003] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on ‘[email protected]’ Request 102: Found
Mar 18 19:17:43 VERBOSE[11424] logger.c: – SIP/3082-08bf5ba0 is ringing
Mar 18 19:17:49 DEBUG[3003] chan_sip.c: Acked pending invite 102
Mar 18 19:17:49 DEBUG[3003] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Mar 18 19:17:49 DEBUG[3003] chan_sip.c: Oooh, we need to change our formats since our peer supports only 0x8 (alaw) and not 0x4 (ulaw)
Mar 18 19:17:49 DEBUG[3003] chan_sip.c: build_route: Contact hop: MS Fax Line
Mar 18 19:17:49 VERBOSE[11424] logger.c: – SIP/3082-08bf5ba0 answered SIP/213.166.5.133-08bf0660
Mar 18 19:17:53 DEBUG[3003] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Mar 18 19:18:09 DEBUG[3003] chan_sip.c: Auto destroying call '[email protected]
Mar 18 19:18:09 WARNING[3003] chan_sip.c: Maximum retries exceeded on transmission

[email protected]
for seqno 101 (Critical Response)
Mar 18 19:18:09 WARNING[3003] chan_sip.c: Hanging up call

[email protected]

  • no reply to our critical packet.
    Mar 18 19:18:09 DEBUG[11424] channel.c: Didn’t get a frame from channel: SIP/213.166.5.133-08bf0660
    Mar 18 19:18:09 DEBUG[11424] channel.c: Bridge stops bridging channels SIP/213.166.5.133-08bf0660 and SIP/3082-08bf5ba0
    Mar 18 19:18:09 DEBUG[11424] chan_sip.c: update_call_counter(3082) - decrement call limit counter
    Mar 18 19:18:09 DEBUG[11424] app_dial.c: Exiting with DIALSTATUS=ANSWER.
    Mar 18 19:18:09 VERBOSE[11424] logger.c: == Spawn extension (macro-dial, s, 10) exited non-zero on ‘SIP/213.166.5.133-08bf0660’ in macro ‘dial’
    Mar 18 19:18:09 VERBOSE[11424] logger.c: == Spawn extension (macro-dial, s, 10) exited non-zero on ‘SIP/213.166.5.133-08bf0660’ in macro ‘exten-vm’
    Mar 18 19:18:09 VERBOSE[11424] logger.c: == Spawn extension (macro-dial, s, 10) exited non-zero on ‘SIP/213.166.5.133-08bf0660’
    Mar 18 19:18:09 VERBOSE[11424] logger.c: – Executing Macro(“SIP/213.166.5.133-08bf0660”, “hangupcall”) in new stack
    Mar 18 19:18:09 VERBOSE[11424] logger.c: – Executing ResetCDR(“SIP/213.166.5.133-08bf0660”, “w”) in new stack
    Mar 18 19:18:09 DEBUG[11424] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
    Mar 18 19:18:09 DEBUG[11424] 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) VALUES (‘2007-03-18 19:17:43’,‘unknown’,’’,‘3082’,‘ext-local’, ‘SIP/213.166.5.133-08bf0660’,‘SIP/3082-08bf5ba0’,‘ResetCDR’,‘w’,26,20,‘ANSWERED’,3,’’)
    Mar 18 19:18:09 VERBOSE[11424] logger.c: – Executing NoCDR(“SIP/213.166.5.133-08bf0660”, “”) in new stack
    Mar 18 19:18:09 NOTICE[11424] cdr.c: CDR on channel ‘SIP/213.166.5.133-08bf0660’ not posted
    Mar 18 19:18:09 NOTICE[11424] cdr.c: CDR on channel ‘SIP/213.166.5.133-08bf0660’ lacks end
    Mar 18 19:18:09 DEBUG[11424] pbx.c: Expression result is '1’
    Mar 18 19:18:09 VERBOSE[11424] logger.c: – Executing GotoIf(“SIP/213.166.5.133-08bf0660”, “1?skiprg”) in new stack
    Mar 18 19:18:09 VERBOSE[11424] logger.c: – Goto (macro-hangupcall,s,6)
    Mar 18 19:18:09 DEBUG[11424] pbx.c: Expression result is '1’
    Mar 18 19:18:09 VERBOSE[11424] logger.c: – Executing GotoIf(“SIP/213.166.5.133-08bf0660”, “1?theend”) in new stack
    Mar 18 19:18:09 VERBOSE[11424] logger.c: – Goto (macro-hangupcall,s,9)
    Mar 18 19:18:09 VERBOSE[11424] logger.c: – Executing Wait(“SIP/213.166.5.133-08bf0660”, “5”) in new stack
    Mar 18 19:18:09 VERBOSE[11424] logger.c: == Spawn extension (macro-hangupcall, s, 9) exited non-zero on ‘SIP/213.166.5.133-08bf0660’ in macro 'hangupcall’
    Mar 18 19:18:09 VERBOSE[11424] logger.c: == Spawn extension (macro-hangupcall, s, 9) exited non-zero on 'SIP/213.166.5.133-08bf0660’
    Mar 18 19:18:09 DEBUG[11424] chan_sip.c: update_call_counter() - decrement call limit counter
    Mar 18 19:18:09 DEBUG[3003] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 103: Match Found
    Mar 18 19:18:12 DEBUG[3003] chan_sip.c: Auto destroying call '[email protected]
    Mar 18 19:18:16 DEBUG[3003] chan_sip.c: Auto destroying call '[email protected]_168_42_253’
    Mar 18 19:18:21 DEBUG[3004] chan_iax2.c: Peer lastms 8, historicms 8, maxms 2000
    Mar 18 19:18:22 DEBUG[3003] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found