[Home]

Summary:ASTERISK-11972: MYSQL() from dialplan appears to "eat" the first field retrieved from a MySQL Table
Reporter:real (albaker)Labels:
Date Opened:2008-05-05 09:25:18Date Closed:2011-06-07 14:03:06
Priority:MajorRegression?No
Status:Closed/CompleteComponents:Addons/app_mysql
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) 12583-reallystrsep.diff
( 1) Asterisk_Log
Description:Thier appears to be a BUG  with the MySQL add-on for Asterisk .This is on FEDORA 8 fully patched with Asterisk Addons 1-4-6 with the Asterisk 1.4.18.1

It appears that the interface “eats” the first field requested from a table. If only One Field is Requested from the Table , that field is eaten ENTIRELY by Asterisk. If several fields are requested, the First Field Is Eaten and the remaining filed are returned, but place in the WRONG Variable since the 1tst field data was eaten. In the DIALPLAN below I have tried 3 Different ways to approach this.

Extension 9999 – Get only ONE (1) field from Table

Extension 8888 – Get THREE(3) fields from the Table and Quote Them.

Extension 7777 - Get THREE(3) fields from the Table

I have show the Output from the Asterisk CLI for each, which clearly show that SOMETHING is not
right. Maybe the Software, maybe the person using the software :) In any event the First Field pulled from the table in not correctly returned to the DialPlan

Here is the Table in the Database.

mysql> select * from agent;

+----------+---------+--------+------------+---------------------+

| id          | cust_id  | status |    phone     |    tlce |

+----------+---------+--------+------------+---------------------+
| 00000001 | NAMB | free | 1234567890 | 2008-04-17 02:32:02 |

| 00000002 | NAMB | free | 2234567890 | 2008-04-17 02:32:02 |

| 00000003 | NAMB | free | 3234567890 | 2008-04-17 02:32:02 |

| 00000004 | NAMB | free | 4234567890 | 2008-04-17 02:32:02 |
+----------+---------+--------+------------+---------------------+

4 rows in set (0.00 sec)


Here is the DIALPLAN

exten => 7777,1,MYSQL(Connect connid localhost ivr ivrxxx dtc)

exten => 7777,n,MYSQL(Query resultid ${connid} SELECT\ cust_id\, \ status\,\ tlce\ from\ agent\ where\ phone=\'1234567890\')

exten => 7777,n,MYSQL(Fetch fetchid ${resultid} custid mystatus mytlce)

exten => 7777,n,NoOp(CUSTID is ${custid} MYSTATUS is ${mystatus} MYTLCE is ${mytlce})

exten => 7777,n,NoOp(FETCHID is ${fetchid} RESULUT ID is .. ${resultid} CONNID is ${connid})

exten => 7777,n,MYSQL(Clear ${resultid})

exten => 7777,n,MYSQL(Disconnect ${connid})

exten => 7777,n,HANGUP



exten => 8888,1,MYSQL(Query resultid ${connid} SELECT\ 'cust_id'\, \ 'status'\,\ 'tlce'\ from\ agent\ where\ phone=\'1234567890\')

exten => 8888,n,MYSQL(Fetch fetchid ${resultid} custid mystatus mytlce)

exten => 8888,n,NoOp(CUSTID is ${custid} MYSTATUS is ${mystatus} MYTLCE is ${mytlce})

exten => 8888,n,NoOp(FETCHID is ${fetchid} RESULUT ID is .. ${resultid} CONNID is ${connid})

exten => 8888,n,MYSQL(Clear ${resultid})

exten => 8888,n,MYSQL(Disconnect ${connid})

exten => 8888,n,HANGUP


exten => 9999,1,MYSQL(Connect connid localhost ivr ivrxxx dtc)

exten => 9999,n,MYSQL(Query resultid ${connid} SELECT\ 'cust_id'\ from\ agent\ where\ phone=\'1234567890\')

exten => 9999,n,MYSQL(Fetch fetchid ${resultid} custid)

exten => 9999,n,NoOp(CUSTID is ${custid})

exten => 9999,n,NoOp(FETCHID is ${fetchid} RESULUT ID is .. ${resultid} CONNID is ${connid})

exten => 9999,n,MYSQL(Clear ${resultid})

exten => 9999,n,MYSQL(Disconnect ${connid})

exten => 9999,n,HANGUP




Here is the Asterisk CLI Output

dial 9999

== Console is full duplex

*CLI> -- Executing [9999@default:1] MYSQL("OSS/dsp", "Connect connid localhost ivr ivrxxx dtc") in new stack

-- Executing [9999@default:2] MYSQL("OSS/dsp", "Query resultid 5 SELECT cust_id from agent where phone='1234567890'") in new stack

-- Executing [9999@default:3] MYSQL("OSS/dsp", "Fetch fetchid 6 custid") in new stack

-- Executing [9999@default:4] NoOp("OSS/dsp", "CUSTID is ") in new stack

-- Executing [9999@default:5] NoOp("OSS/dsp", "FETCHID is 1 RESULUT ID is .. 6 CONNID is 5") in new stack

-- Executing [9999@default:6] MYSQL("OSS/dsp", "Clear 6") in new stack

-- Executing [9999@default:7] MYSQL("OSS/dsp", "Disconnect 5") in new stack

-- Executing [9999@default:8] Hangup("OSS/dsp", "") in new stack

== Spawn extension (default, 9999, 8) exited non-zero on 'OSS/dsp'

<< Hangup on console

*CLI> dial 8888

== Console is full duplex

*CLI> -- Executing [8888@default:1] MYSQL("OSS/dsp", "Connect connid localhost ivr ivrxxx dtc") in new stack

-- Executing [8888@default:2] MYSQL("OSS/dsp", "Query resultid 5 SELECT cust_id, status, tlce from agent where phone='1234567890'") in new stack

-- Executing [8888@default:3] MYSQL("OSS/dsp", "Fetch fetchid 6 custid mystatus mytlce") in new stack

-- Executing [8888@default:4] NoOp("OSS/dsp", "CUSTID is free MYSTATUS is 2008-04-17 02:32:02 MYTLCE is ") in new stack

-- Executing [8888@default:5] NoOp("OSS/dsp", "FETCHID is 1 RESULUT ID is .. 6 CONNID is 5") in new stack

-- Executing [8888@default:6] MYSQL("OSS/dsp", "Clear 6") in new stack

-- Executing [8888@default:7] MYSQL("OSS/dsp", "Disconnect 5") in new stack

-- Executing [8888@default:8] Hangup("OSS/dsp", "") in new stack

== Spawn extension (default, 8888, 8) exited non-zero on 'OSS/dsp'

<< Hangup on console >

OK – Have I done something really dumb or is this a BUG ?
Thank VERY MUCH for any and ALL Help
Comments:By: Donny Kavanagh (donnyk) 2008-05-05 10:34:32

Can you set your debug and verbosity to 10 and rerun one or more of your tests and provide the output.  Theres some debug in the code i'd like to see to see if it gives any clues.
By: Donny Kavanagh (donnyk) 2008-05-05 10:39:31

Ignore that, the extra logging is in trunk only, you would need to compile with EXTRA_LOG defined to see it in 1.4.
By: Donny Kavanagh (donnyk) 2008-05-05 14:27:16

Can you please update this bug with your platform, eg, linux version, mysql client version, and so on.
By: Jason Parker (jparker) 2008-05-05 14:53:34

Patch uploaded.  Give that a try?
By: Jason Parker (jparker) 2008-05-05 15:35:15

On second thought, I'm pretty sure this patch is wrong.  Can you please show debug output here?
By: real (albaker) 2008-05-06 16:18:43

I would like to provide any and all info that would be helpful to you.
I must admit my ignorance about exactly "how" to do that and after looking over the notes I'm confused as to "what" I should or should not do.

To answer the note # 0086420: FEDORA 8 fully patched with Asterisk Addons 1-4-6 with the Asterisk 1.4.18.1 on a SONY laptop.

If you could be a bit more didactic in what you want (Run command xxx in directory yyy and pot output) I am glad to run/try/test anything you would like.
Thank You
By: Donny Kavanagh (donnyk) 2008-05-06 19:30:22

Basically, we need you to set debug and verbose to 10, then run the call and get the output from the console.
By: Joshua C. Colp (jcolp) 2008-05-07 08:40:34

You will also need to add debug to logger.conf to go to console if it is not already there.
By: real (albaker) 2008-05-07 18:46:39

This is a cut paste from last part of log file. I cannot see how to get all 925 lines to you. FULL FILE also SENT
==============
[May  7 19:36:30] ^[[1;32;40mDEBUG^[[0;37;40m[4331]: ^[[1;37;40mres_config_mysql.c^[[0;37;40m:^[[1;37;40m591^[[0;37;40m ^[[1;37;40mparse_config^[[0;37;40m: MySQL RealTime User: asterisk
[May  7 19:36:30] ^[[1;32;40mDEBUG^[[0;37;40m[4331]: ^[[1;37;40mres_config_mysql.c^[[0;37;40m:^[[1;37;40m592^[[0;37;40m ^[[1;37;40mparse_config^[[0;37;40m: MySQL RealTime Password: mawxxx
[May  7 19:36:30] ^[[31;40mERROR^[[0;37;40m[4331]: ^[[1;37;40mres_config_mysql.c^[[0;37;40m:^[[1;37;40m629^[[0;37;40m ^[[1;37;40mmysql_reconnect^[[0;37;40m: MySQL RealTime: Failed to connect database server dtc on 127.0.0.1 (err 1044). Check debug for more info.
[May  7 19:36:30] ^[[1;32;40mDEBUG^[[0;37;40m[4331]: ^[[1;37;40mres_config_mysql.c^[[0;37;40m:^[[1;37;40m630^[[0;37;40m ^[[1;37;40mmysql_reconnect^[[0;37;40m: MySQL RealTime: Cannot Connect (1044): Access denied for user 'asterisk'@'localhost' to database 'dtc'
[May  7 19:36:30] ^[[1;31;40mWARNING^[[0;37;40m[4331]: ^[[1;37;40mres_config_mysql.c^[[0;37;40m:^[[1;37;40m476^[[0;37;40m ^[[1;37;40mload_module^[[0;37;40m: MySQL RealTime: Couldn't establish connection. Check debug.
[May  7 19:36:30] ^[[1;32;40mDEBUG^[[0;37;40m[4331]: ^[[1;37;40mres_config_mysql.c^[[0;37;40m:^[[1;37;40m477^[[0;37;40m ^[[1;37;40mload_module^[[0;37;40m: MySQL RealTime: Cannot Connect: Access denied for user 'asterisk'@'localhost' to database 'dtc'
[May  7 19:36:30] ^[[1;33;40mNOTICE^[[0;37;40m[4331]: ^[[1;37;40mconfig.c^[[0;37;40m:^[[1;37;40m1259^[[0;37;40m ^[[1;37;40mast_config_engine_register^[[0;37;40m: Registered Config Engine mysql
MySQL RealTime driver loaded.
res_config_mysql.so => (^[[33;40mMySQL RealTime Configuration Driver^[[0;37;40m)
^[[1;37;40mAsterisk Ready.
^[[0;37;40m^[]1;Asterisk^G^[]2;Asterisk Console on 'testbox' (pid 4331)^G*CLI> dial 8888^M
^[[0;37;40m^[[1;30;40m  == ^[[0;37;40mConsole is full duplex
The 'dial' command is deprecated and will be removed in a future release. Please use 'console dial' instead.
*CLI> ^[[1;30;40m    -- ^[[0;37;40mExecuting [8888@default:1] ^[[1;36;40mMYSQL^[[0;37;40m("^[[1;35;40mOSS/dsp^[[0;37;40m", "^[[1;35;40mConnect connid localhost ivr ivrxxx dtc^[[0;37;40m") in new stack
^[[1;30;40m    -- ^[[0;37;40mExecuting [8888@default:2] ^[[1;36;40mMYSQL^[[0;37;40m("^[[1;35;40mOSS/dsp^[[0;37;40m", "^[[1;35;40mQuery resultid 1 SELECT cust_id,  status, tlce from agent where phone='1234567890'^[[0;37;40m") in new stack
^[[1;30;40m    -- ^[[0;37;40mExecuting [8888@default:3] ^[[1;36;40mMYSQL^[[0;37;40m("^[[1;35;40mOSS/dsp^[[0;37;40m", "^[[1;35;40mFetch fetchid 2  custid mystatus mytlce^[[0;37;40m") in new stack
^[[1;30;40m    -- ^[[0;37;40mExecuting [8888@default:4] ^[[1;36;40mNoOp^[[0;37;40m("^[[1;35;40mOSS/dsp^[[0;37;40m", "^[[1;35;40mCUSTID is free  MYSTATUS is 2008-04-17 02:32:02  MYTLCE is ^[[0;37;40m") in new stack
^[[1;30;40m    -- ^[[0;37;40mExecuting [8888@default:5] ^[[1;36;40mNoOp^[[0;37;40m("^[[1;35;40mOSS/dsp^[[0;37;40m", "^[[1;35;40mFETCHID is 1  RESULUT ID is .. 2 CONNID is 1^[[0;37;40m") in new stack
^[[1;30;40m    -- ^[[0;37;40mExecuting [8888@default:6] ^[[1;36;40mMYSQL^[[0;37;40m("^[[1;35;40mOSS/dsp^[[0;37;40m", "^[[1;35;40mClear 2^[[0;37;40m") in new stack
^[[1;30;40m    -- ^[[0;37;40mExecuting [8888@default:7] ^[[1;36;40mMYSQL^[[0;37;40m("^[[1;35;40mOSS/dsp^[[0;37;40m", "^[[1;35;40mDisconnect 1^[[0;37;40m") in new stack
^[[1;30;40m    -- ^[[0;37;40mExecuting [8888@default:8] ^[[1;36;40mHangup^[[0;37;40m("^[[1;35;40mOSS/dsp^[[0;37;40m", "^[[1;35;40m^[[0;37;40m") in new stack
^[[1;30;40m  == ^[[0;37;40mSpawn extension (default, 8888, 8) exited non-zero on 'OSS/dsp'
^[[1;30;40m ^[[0;37;40m<< Hangup on console >>
^M
^[[0;37;40m*CLI>
================================================

Please advise on what else I can provide you that would be helpful.


By: Jason Parker (jparker) 2008-05-08 10:25:35

You have extra spaces in your Fetch (and potentially other) statements.

This is not an issue in Asterisk, and it is not something we plan on changing.

Remove extra spaces, and please do not sanitize logs or dialplan in future reports.  This is something that could have been caught immediately if they hadn't been cleaned.
By: real (albaker) 2008-05-08 14:05:12

Whaooo
1st off I didn't 'sanitze' any log files.
I posted what I had the way they are. What the heck would I have 'sanitized' and why ? What came up on the CLI is what I posted!

This is the Exact Line from the DialPlan
==========================================
exten=> 8888,n,MYSQL(Fetch fetchid ${resultid} custid mystatus mytlce)
==================================================

This is the detailed log line
==============================
^[[1;30;40m -- ^[[0;37;40mExecuting [8888@default:3] ^[[1;36;40mMYSQL^[[0;37;40m("^[[1;35;40mOSS/dsp^[[0;37;40m", "^[[1;35;40mFetch fetchid 2 custid mystatus mytlce^[[0;37;40m") in new stack
=========================================================

So after all of this, could you be so kind as to say where Exactly the supposed 'Extra Space' is ?  1) I mean I haven't seen it
2) no one on the mailing list has seen it.
3) You didn't see it
4) The Asterisk interpreter didn't complain about it..

So could you be just SLIGHTLY more specific as to where the problem is.

Thank You



By: Jason Parker (jparker) 2008-05-08 14:11:01

From the log that you posted earlier:

Executing [8888@default:3] MYSQL("OSS/dsp", "Fetch<SPACE>fetchid<SPACE>2<SPACE><SPACE>custid<SPACE>mystatus<SPACE>mytlce") in new stack

Between the 2 and custid.


Edit: Added "Executing" part.


By: real (albaker) 2008-05-08 14:27:27

OK
I will go back and check the dial plan again.
I will try to eliminate any spaces
If it fails, I will try to post the line from the dialplan such that there is absolutely no ambaguity as to its format.

If I may offer the thought, even if this IS the problem, it might be better if the intrepeter gave a error message or the documentation was EXPLICIT in the critcality of this. With all the "escapeling"  and "backslahshing" that is already required in the MYSQL interface this degree of sensitivity and lack of error or warning message seems like an accident waiting to happen
By: Jason Parker (jparker) 2008-05-08 14:42:51

The only place escaping would be necessary is before a comma.

I would actually consider this to be a feature.  There are cases where you want to simply ignore a variable - to do that, you would just need to add an extra space as you have.  It would be similar to using Dial(Zap/1,,g) when you want to set an option without setting a timeout.  Without changing the syntax of the application (and at that point - we may as well rewrite it entirely (and THEN, you might as well just use func_odbc)), this isn't something that I expect is going to change.

As far as "sanitizing" logs, maybe I should have worded that better.  I certainly didn't mean that you did it intentionally.  Perhaps you are using some HTML GUI that would hide the extra spaces (browsers have a habit of doing that - I guess it's part of the HTML specs).