[Asterisk-Users] Realtime and PostgreSQL
Clay Reiche
creiche at accxx.com
Sat Dec 18 23:37:40 MST 2004
I was dloading cvs over the top of a stable branch... (Matthew told me that
was a no-no...)
I've made progress but I'm still havng some troubles. I can get my devices to
register but when I try to make a call, I get silence and some SQL failures.
Below is console output from bootup to registration to placing a call. Thanks
in advance!
Console bootup:
[res_odbc.so] => (ODBC Resource)
== Parsing '/etc/asterisk/res_odbc.conf': Found Dec 18 10:58:26
NOTICE[9982]: res_odbc.c:133 load_odbc_config: registered database handle
'PostgreSQL' dsn->[PostgreSQL] Dec 18 10:58:26 NOTICE[9982]: res_odbc.c:345
odbc_obj_connect: Calling 0x8bbf070/0x8bbf080 Dec 18 10:58:26 NOTICE[9982]:
res_odbc.c:359 odbc_obj_connect: res_odbc: Connected to PostgreSQL
[PostgreSQL] Dec 18 10:58:26 NOTICE[9982]: res_odbc.c:385 load_module:
res_odbc loaded.
[res_config_odbc.so] => (ODBC Configuration) Dec 18 10:58:26 NOTICE[9982]:
config.c:641 ast_config_register: Registered Config Engine odbc
== Parsing '/etc/asterisk/extconfig.conf': Found
== Binding sipfriends to odbc/PostgreSQL/sip_conf
== Binding extensions to odbc/PostgreSQL/extensions_conf
== Binding voicemail to odbc/PostgreSQL/voicemail_conf res_config_odbc
loaded.
[pbx_config.so] => (Text Extension Configuration)
== Parsing '/etc/asterisk/extensions.conf': Found
-- Setting global variable 'CONSOLE' to 'Console/dsp'
-- Setting global variable 'IAXINFO' to 'guest'
-- Setting global variable 'TRUNK' to 'Zap/g2'
-- Setting global variable 'TRUNKMSD' to '1'
-- Registered extension context 'iaxtel700'
-- Added extension '_91700XXXXXXX' priority 1 to iaxtel700
-- Registered extension context 'iaxprovider'
-- Registered extension context 'trunkint'
-- Added extension '_9011.' priority 1 to trunkint
-- Added extension '_9011.' priority 2 to trunkint
-- Registered extension context 'trunkld'
-- Added extension '_91NXXNXXXXXX' priority 1 to trunkld
-- Added extension '_91NXXNXXXXXX' priority 2 to trunkld
-- Registered extension context 'trunklocal'
-- Added extension '_9NXXXXXX' priority 1 to trunklocal
-- Added extension '_9NXXXXXX' priority 2 to trunklocal
-- Registered extension context 'trunktollfree'
-- Added extension '_91800NXXXXXX' priority 1 to trunktollfree
-- Added extension '_91800NXXXXXX' priority 2 to trunktollfree
-- Added extension '_91888NXXXXXX' priority 1 to trunktollfree
-- Added extension '_91888NXXXXXX' priority 2 to trunktollfree
-- Added extension '_91877NXXXXXX' priority 1 to trunktollfree
-- Added extension '_91877NXXXXXX' priority 2 to trunktollfree
-- Added extension '_91866NXXXXXX' priority 1 to trunktollfree
-- Added extension '_91866NXXXXXX' priority 2 to trunktollfree
-- Registered extension context 'international'
-- Including context 'longdistance' in context 'international'
-- Including context 'trunkint' in context 'international'
-- Registered extension context 'longdistance'
-- Including context 'local' in context 'longdistance'
-- Including context 'trunkld' in context 'longdistance'
-- Registered extension context 'local'
-- Including context 'default' in context 'local'
-- Including context 'parkedcalls' in context 'local'
-- Including context 'trunklocal' in context 'local'
-- Including context 'iaxtel700' in context 'local'
-- Including context 'trunktollfree' in context 'local'
-- Including context 'iaxprovider' in context 'local'
-- Including context 'from-sip' in context 'local'
-- Registered extension context 'macro-stdexten'
-- Added extension 's' priority 1 to macro-stdexten
-- Added extension 's' priority 2 to macro-stdexten
-- Added extension 's-NOANSWER' priority 1 to macro-stdexten
-- Added extension 's-NOANSWER' priority 2 to macro-stdexten
-- Added extension 's-BUSY' priority 1 to macro-stdexten
-- Added extension 's-BUSY' priority 2 to macro-stdexten
-- Added extension '_s-.' priority 1 to macro-stdexten
-- Added extension 'a' priority 1 to macro-stdexten
-- Registered extension context 'demo'
-- Added extension 's' priority 1 to demo
-- Added extension 's' priority 2 to demo
-- Added extension 's' priority 3 to demo
-- Added extension 's' priority 4 to demo
-- Added extension 's' priority 5 to demo
-- Added extension 's' priority 6 to demo
-- Added extension '2' priority 1 to demo
-- Added extension '2' priority 2 to demo
-- Added extension '3' priority 1 to demo
-- Added extension '3' priority 2 to demo
-- Added extension '1000' priority 1 to demo
-- Added extension '1234' priority 1 to demo
-- Added extension '1234' priority 2 to demo
-- Added extension '1235' priority 1 to demo
-- Added extension '1236' priority 1 to demo
-- Added extension '1236' priority 2 to demo
-- Added extension '#' priority 1 to demo
-- Added extension '#' priority 2 to demo
-- Added extension 't' priority 1 to demo
-- Added extension 'i' priority 1 to demo
-- Added extension '500' priority 1 to demo
-- Added extension '500' priority 2 to demo
-- Added extension '500' priority 3 to demo
-- Added extension '500' priority 4 to demo
-- Added extension '600' priority 1 to demo
-- Added extension '600' priority 2 to demo
-- Added extension '600' priority 3 to demo
-- Added extension '600' priority 4 to demo
-- Added extension '8500' priority 1 to demo
-- Added extension '8500' priority 2 to demo
-- Registered extension context 'default'
-- Including context 'demo' in context 'default'
-- Added extension '8500' priority 1 to default
-- Added extension '8500' priority 2 to default
-- Registered extension context 'outboundmsg1'
-- Added extension 's' priority 1 to outboundmsg1
-- Added extension 's' priority 2 to outboundmsg1
-- Added extension 's' priority 3 to outboundmsg1
-- Added extension 's' priority 4 to outboundmsg1
-- Added extension 's' priority 5 to outboundmsg1
-- Added extension 's' priority 6 to outboundmsg1
-- Added extension '1' priority 1 to outboundmsg1
-- Added extension '2' priority 1 to outboundmsg1
-- Added extension 't' priority 1 to outboundmsg1
-- Added extension 't' priority 2 to outboundmsg1
-- Registered extension context 'outboundmsg2'
-- Added extension 's' priority 1 to outboundmsg2
-- Added extension 's' priority 2 to outboundmsg2
-- Added extension 's' priority 3 to outboundmsg2
-- Added extension 's' priority 4 to outboundmsg2
-- Added extension 's' priority 5 to outboundmsg2
-- Added extension 's' priority 6 to outboundmsg2
-- Added extension '1' priority 1 to outboundmsg2
-- Added extension '2' priority 1 to outboundmsg2
-- Added extension 't' priority 1 to outboundmsg2
-- Added extension 't' priority 2 to outboundmsg2
-- Registered extension context 'msgack'
-- Added extension 's' priority 1 to msgack
-- Added extension 's' priority 2 to msgack
-- Added extension 's' priority 3 to msgack
-- Registered extension context 'record-outboundmsgs'
-- Added extension '2051' priority 1 to record-outboundmsgs
-- Added extension '2051' priority 2 to record-outboundmsgs
-- Added extension '2051' priority 3 to record-outboundmsgs
-- Added extension '2051' priority 4 to record-outboundmsgs
-- Added extension '2051' priority 5 to record-outboundmsgs
-- Added extension '2051' priority 6 to record-outboundmsgs
-- Added extension '2052' priority 1 to record-outboundmsgs
-- Added extension '2052' priority 2 to record-outboundmsgs
-- Added extension '2052' priority 3 to record-outboundmsgs
-- Added extension '2052' priority 4 to record-outboundmsgs
-- Added extension '2052' priority 5 to record-outboundmsgs
-- Added extension '2052' priority 6 to record-outboundmsgs
-- Added extension '2061' priority 1 to record-outboundmsgs
-- Added extension '2061' priority 2 to record-outboundmsgs
-- Added extension '2061' priority 3 to record-outboundmsgs
-- Added extension '2061' priority 4 to record-outboundmsgs
-- Added extension '2061' priority 5 to record-outboundmsgs
-- Added extension '2061' priority 6 to record-outboundmsgs
-- Added extension '2062' priority 1 to record-outboundmsgs
-- Added extension '2062' priority 2 to record-outboundmsgs
-- Added extension '2062' priority 3 to record-outboundmsgs
-- Added extension '2062' priority 4 to record-outboundmsgs
-- Added extension '2062' priority 5 to record-outboundmsgs
-- Added extension '2062' priority 6 to record-outboundmsgs
-- Registered extension context 'from-sip'
-- Including switch 'Realtime/from-sip at extensions' in context 'from-sip'
[pbx_loopback.so] => (Loopback Switch)
[cdr_odbc.so] => (ODBC CDR Backend)
== Parsing '/etc/asterisk/cdr_odbc.conf': Found [format_g729.so] => (Raw
G729 data)
[cdr_pgsql.so] => (PostgreSQL CDR Backend)
== Parsing '/etc/asterisk/cdr_pgsql.conf': Found Dec 18 10:58:27
WARNING[9982]: cdr_pgsql.c:298 process_my_load_module: CDR table not
specified. Assuming cdr Dec 18 10:58:27 DEBUG[9982]: cdr_pgsql.c:302
process_my_load_module: cdr_pgsql: got hostname of localhost Dec 18 10:58:27
DEBUG[9982]: cdr_pgsql.c:303 process_my_load_module: cdr_pgsql: got port of
5432 Dec 18 10:58:27 DEBUG[9982]: cdr_pgsql.c:306 process_my_load_module:
cdr_pgsql: got user of abox Dec 18 10:58:27 DEBUG[9982]: cdr_pgsql.c:307
process_my_load_module: cdr_pgsql: got dbname of asterisk Dec 18 10:58:27
DEBUG[9982]: cdr_pgsql.c:308 process_my_load_module: cdr_pgsql: got password
of ecom1091 Dec 18 10:58:27 DEBUG[9982]: cdr_pgsql.c:309
process_my_load_module: cdr_pgsql: got sql table name of cdr Dec 18 10:58:27
DEBUG[9982]: cdr_pgsql.c:313 process_my_load_module: Successfully connected
to PostgreSQL database.
[format_pcm.so] => (Raw uLaw 8khz Audio support (PCM))
== Registered file format pcm, extension(s) pcm|ulaw|ul|mu [format_gsm.so]
=> (Raw GSM data)
== Registered file format gsm, extension(s) gsm [app_enumlookup.so] =>
(ENUM Lookup)
== Registered application 'EnumLookup'
== Parsing '/etc/asterisk/enum.conf': Found [app_voicemail.so] =>
(Comedian Mail (Voicemail System))
== Registered application 'VoiceMail'
== Registered application 'VoiceMailMain'
== Registered application 'MailboxExists'
== Registered application 'VMAuthenticate'
== Parsing '/etc/asterisk/voicemail.conf': Found Dec 18 10:58:27
DEBUG[9982]: app_voicemail.c:5139 load_config: VM Review Option disabled
globally Dec 18 10:58:27 DEBUG[9982]: app_voicemail.c:5146 load_config: VM
Operator break disabled globally Dec 18 10:58:27 DEBUG[9982]:
app_voicemail.c:5153 load_config: VM CID Info before msg disabled globally
Dec 18 10:58:27 DEBUG[9982]: app_voicemail.c:5167 load_config: ENVELOPE
before msg enabled globally Dec 18 10:58:27 DEBUG[9982]: app_voicemail.c:5174
load_config: Duration info before msg enabled globally Dec 18 10:58:27
DEBUG[9982]: app_voicemail.c:5190 load_config: We are not going to skip to
the next msg after save/delete [app_dumpchan.so] => (Dump Info About The
Calling Channel)
== Registered application 'DumpChan'
[app_addon_sql_mysql.so] => (Simple Mysql Interface)
== Registered application 'MYSQL'
[cdr_addon_mysql.so] => (MySQL CDR Backend)
== Parsing '/etc/asterisk/cdr_mysql.conf': Found [app_meetme.so] =>
(MeetMe conference bridge)
== Registered application 'MeetMeAdmin'
== Registered application 'MeetMeCount'
== Registered application 'MeetMe'
*CLI>
=============================================================================
=======================
Device registration:
*CLI> -- SIP Seeding '5555' at 5555 at 65.35.190.238:5060 for 660
-- SIP Seeding '5556' at 5556 at 65.35.190.238:5060 for 660
-- SIP Seeding '5555' at 5555 at 65.35.190.238:5060 for 660 Dec 18 11:07:43
NOTICE[9982]: chan_sip.c:8094 sip_poke_peer: Still have a call...
-- Registered SIP '5555' at 65.35.190.238 port 5060 expires 660
-- Saved useragent "WATA200 Callctrl/1.5.1.1 MxSF/v3.2.6.26" for peer
5555 Dec 18 11:07:43 WARNING[9982]: res_config_odbc.c:374 update_odbc: SQL
Prepare failed![UPDATE sip_conf SET ipaddr=?, port=?, regseconds=?,
username=? WHERE name=?]
-- SIP Seeding '5555' at 5555 at 65.35.190.238:5060 for 660 Dec 18 11:07:43
DEBUG[9982]: app_queue.c:371 changethread: Device 'SIP/5555' changed to state
'5'
Dec 18 11:07:43 DEBUG[9982]: chan_sip.c:7311 handle_request: That's odd...
Got a response on a call we dont know about.
-- SIP Seeding '5556' at 5556 at 65.35.190.238:5060 for 660 Dec 18 11:07:43
NOTICE[9982]: chan_sip.c:8094 sip_poke_peer: Still have a call...
-- Registered SIP '5556' at 65.35.190.238 port 5060 expires 660
-- Saved useragent "WATA200 Callctrl/1.5.1.1 MxSF/v3.2.6.26" for peer
5556 Dec 18 11:07:43 WARNING[9982]: res_config_odbc.c:374 update_odbc: SQL
Prepare failed![UPDATE sip_conf SET ipaddr=?, port=?, regseconds=?,
username=? WHERE name=?]
-- SIP Seeding '5556' at 5556 at 65.35.190.238:5060 for 660 Dec 18 11:07:43
DEBUG[9982]: app_queue.c:371 changethread: Device 'SIP/5556' changed to state
'5'
Dec 18 11:07:43 DEBUG[9982]: chan_sip.c:7311 handle_request: That's odd...
Got a response on a call we dont know about.
Dec 18 11:07:43 DEBUG[9982]: chan_sip.c:7311 handle_request: That's odd...
Got a response on a call we dont know about.
Dec 18 11:07:43 DEBUG[9982]: chan_sip.c:7311 handle_request: That's odd...
Got a response on a call we dont know about.
Dec 18 11:07:43 DEBUG[9982]: chan_sip.c:7311 handle_request: That's odd...
Got a response on a call we dont know about.
Dec 18 11:07:43 DEBUG[9982]: chan_sip.c:7311 handle_request: That's odd...
Got a response on a call we dont know about.
Dec 18 11:07:58 DEBUG[9982]: chan_sip.c:783 __sip_autodestruct: Auto
destroying call '171698e7c4cd268eb23213d5cf945e84 at 192.168.1.101'
Dec 18 11:07:58 DEBUG[9982]: chan_sip.c:783 __sip_autodestruct: Auto
destroying call 'b6bcbbccf5fd4022b3577bc6d7be5486 at 192.168.1.101'
=============================================================================
============================================================
Phone Call attempt:
*CLI> Dec 18 11:10:59 DEBUG[9982]: chan_sip.c:5449 check_user_full: Setting
NAT on RTP to 4 Dec 18 11:10:59 DEBUG[9982]: chan_sip.c:852 __sip_ack:
Stopping retransmission on '124078fd2b2f1c66485d4040fe5dab68 at 192.168.1.101'
of Response 823061699: Found Dec 18 11:10:59 DEBUG[9982]: chan_sip.c:5449
check_user_full: Setting NAT on RTP to 4 Dec 18 11:10:59 DEBUG[9982]:
chan_sip.c:7398 handle_request: Check for res for 5555 Dec 18 11:10:59
DEBUG[9982]: chan_sip.c:1586 update_user_counter: Call from user '5555' is 1
out of 0 Dec 18 11:10:59 DEBUG[9982]: chan_sip.c:4659 build_route:
build_route: Contact hop: Accxx <sip:5555 at 192.168.1.101>
-- SIP Seeding '5555' at 5555 at 65.35.190.238:5060 for 660 Dec 18 11:10:59
DEBUG[9982]: app_queue.c:371 changethread: Device 'SIP/5555' changed to state
'5'
-- Executing Dial("SIP/5555-5e1b", "SIP/5556,20") Dec 18 11:10:59
WARNING[9982]: chan_sip.c:1357 create_addr: No such host: 5556,20 Dec 18
11:10:59 NOTICE[9982]: app_dial.c:803 dial_exec: Unable to create channel of
type 'SIP' (cause 3)
== Everyone is busy/congested at this time (1:0/1/0) Dec 18 11:10:59
WARNING[9982]: res_config_odbc.c:250 realtime_multi_odbc: SQL Execute error!
[SELECT * FROM extensions_conf WHERE exten RLIKE ? AND context = ? AND
priority = ? ORDER BY exten]
Dec 18 11:10:59 DEBUG[9982]: app_dial.c:1167 dial_exec: Exiting with
DIALSTATUS=CONGESTION.
-- Executing Voicemail("SIP/5555-5e1b", "u5556") Dec 18 11:10:59
WARNING[9982]: app_voicemail.c:2208 leave_voicemail: No entry in voicemail
config file for '5556'
Dec 18 11:10:59 WARNING[9982]: res_config_odbc.c:250 realtime_multi_odbc: SQL
Execute error!
[SELECT * FROM extensions_conf WHERE exten RLIKE ? AND context = ? AND
priority = ? ORDER BY exten]
Dec 18 11:10:59 WARNING[9982]: res_config_odbc.c:250 realtime_multi_odbc: SQL
Execute error!
[SELECT * FROM extensions_conf WHERE exten RLIKE ? AND context = ? AND
priority = ? ORDER BY exten]
Dec 18 11:10:59 DEBUG[9982]: chan_sip.c:852 __sip_ack: Stopping
retransmission on '124078fd2b2f1c66485d4040fe5dab68 at 192.168.1.101' of
Response 823061700: Found Dec 18 11:11:00 DEBUG[9982]: chan_sip.c:7311
handle_request: That's odd... Got a response on a call we dont know about.
Dec 18 11:11:00 DEBUG[9982]: rtp.c:471 ast_rtp_read: RTP NAT: Using address
65.35.190.238:27000 Dec 18 11:11:00 DEBUG[9982]: rtp.c:391 ast_rtcp_read: RTP
NAT: Using address 192.168.1.101:27001 Dec 18 11:11:00 DEBUG[9982]: rtp.c:471
ast_rtp_read: RTP NAT: Using address 65.35.190.238:27000 Dec 18 11:11:03
DEBUG[9982]: rtp.c:391 ast_rtcp_read: RTP NAT: Using address
192.168.1.101:27001 Dec 18 11:11:03 DEBUG[9982]: rtp.c:471 ast_rtp_read: RTP
NAT: Using address 65.35.190.238:27000 Dec 18 11:11:06 DEBUG[9982]: rtp.c:391
ast_rtcp_read: RTP NAT: Using address 192.168.1.101:27001 Dec 18 11:11:06
DEBUG[9982]: rtp.c:471 ast_rtp_read: RTP NAT: Using address
65.35.190.238:27000 Dec 18 11:11:09 DEBUG[9982]: rtp.c:391 ast_rtcp_read: RTP
NAT: Using address 192.168.1.101:27001 Dec 18 11:11:09 DEBUG[9982]: rtp.c:471
ast_rtp_read: RTP NAT: Using address 65.35.190.238:27000 Dec 18 11:11:10
WARNING[9982]: res_config_odbc.c:250 realtime_multi_odbc: SQL Execute error!
[SELECT * FROM extensions_conf WHERE exten RLIKE ? AND context = ? AND
priority = ? ORDER BY exten]
Dec 18 11:11:10 WARNING[9982]: res_config_odbc.c:250 realtime_multi_odbc: SQL
Execute error!
[SELECT * FROM extensions_conf WHERE exten RLIKE ? AND context = ? AND
priority = ? ORDER BY exten]
Dec 18 11:11:10 WARNING[9982]: pbx.c:2000 ast_pbx_run: Timeout, but no rule
't' in context 'from-sip'
Dec 18 11:11:10 WARNING[9982]: res_config_odbc.c:250 realtime_multi_odbc: SQL
Execute error!
[SELECT * FROM extensions_conf WHERE exten RLIKE ? AND context = ? AND
priority = ? ORDER BY exten]
Dec 18 11:11:10 DEBUG[9982]: cdr_pgsql.c:100 pgsql_log: cdr_pgsql: inserting
a CDR record.
Dec 18 11:11:10 DEBUG[9982]: cdr_pgsql.c:108 pgsql_log: cdr_pgsql: SQL
command executed: INSERT INTO cdr
(calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,
billsec,disposition,amaflags,accountcode,uniqueid,userfield) VALUES
('2004-12-18 11:10:59','"Clay 5555" <5555>','5555','5556','from-sip',
'SIP/5555-5e1b','','VoiceMail','u5556',11,11,'ANSWERED',3,'DEFAULT_GROUP','11
03386259.0','')
Dec 18 11:11:10 DEBUG[9982]: chan_sip.c:1691 sip_hangup:
update_user_counter(5555) - decrement inUse counter
-- SIP Seeding '5555' at 5555 at 65.35.190.238:5060 for 660 Dec 18 11:11:10
DEBUG[9982]: app_queue.c:371 changethread: Device 'SIP/5555' changed to state
'5'
Dec 18 11:11:10 DEBUG[9982]: chan_sip.c:852 __sip_ack: Stopping
retransmission on '124078fd2b2f1c66485d4040fe5dab68 at 192.168.1.101' of Request
102: Found Dec 18 11:11:10 DEBUG[9982]: chan_sip.c:7311 handle_request:
That's odd... Got a response on a call we dont know about.
Thanks again!
-Clay
More information about the asterisk-users
mailing list