| 00:26.35 | *** join/#asterisk-bugs mackes (n=root@cpe-24-198-43-238.buffalo.res.rr.com) |
| 01:22.05 | *** join/#asterisk-bugs lmadsen (n=Leif@asterisk/documenteur-extraordinaire/blitzrage) |
| 01:22.05 | *** mode/#asterisk-bugs [+o lmadsen] by ChanServ |
| 01:27.18 | *** join/#asterisk-bugs mvanbaak (n=michiel@vanbaak.xs4all.nl) |
| 07:20.23 | *** join/#asterisk-bugs oej (n=olle@ns.webway.se) |
| 09:40.01 | *** join/#asterisk-bugs oej (n=olle@ns.webway.se) |
| 11:03.19 | *** join/#asterisk-bugs lmadsen (n=Leif@asterisk/documenteur-extraordinaire/blitzrage) |
| 11:03.19 | *** mode/#asterisk-bugs [+o lmadsen] by ChanServ |
| 11:15.23 | *** join/#asterisk-bugs oej (n=olle@ns.webway.se) |
| 11:24.15 | *** join/#asterisk-bugs DagMoller (n=aguirre@unaffiliated/dagmoller) |
| 13:23.01 | *** join/#asterisk-bugs dawebber (n=dawebber@209.136.161.135) |
| 13:30.47 | *** join/#asterisk-bugs caio1982 (i=caio1982@CAcert-br/caio1982) |
| 13:44.02 | *** join/#asterisk-bugs bbryant (n=brett@216.207.245.1) |
| 13:44.02 | *** mode/#asterisk-bugs [+o bbryant] by ChanServ |
| 13:46.56 | *** join/#asterisk-bugs putnopvut (n=putnopvu@216.207.245.1) |
| 13:46.56 | *** mode/#asterisk-bugs [+o putnopvut] by ChanServ |
| 13:59.16 | dawebber | folks, I was wondering if anyone ever had a run-in with http://bugs.digium.com/view.php?id=12595 |
| 13:59.51 | dawebber | I know usually this is some sort of CDR taking forever issue, but this doesn't seem to be the case here, IMO. |
| 13:59.59 | dawebber | I've attached PRI DEBUG |
| 14:25.16 | dawebber | what I don't understand, is if a call comes in from the PRI and the channel is messed up, why can't Asterisk skip it and go on to the next channel, if available. This may be Zap-specific, but still |
| 14:26.50 | *** join/#asterisk-bugs fakhir (n=fakhir@unaffiliated/fakhir) |
| 14:29.28 | *** join/#asterisk-bugs russellb (n=russell@asterisk/developer-and-stable-maintainer/drumkilla) |
| 14:29.28 | *** mode/#asterisk-bugs [+o russellb] by ChanServ |
| 14:48.10 | *** join/#asterisk-bugs jpeeler (n=jpeeler@216.207.245.1) |
| 15:26.13 | dawebber | russell: I think Dimas and I need your input on http://bugs.digium.com/view.php?id=12592 |
| 15:26.57 | dawebber | russellb: could you please let me know what your thoughts are on that? |
| 15:27.10 | file | M12592 |
| 15:27.12 | MuffinMan | [new] [Asterisk] Channels/chan_zap 0012592: DTMF issues in 1.4.19 with missing digits reported by dawebber (Karma: neutral) http://bugs.digium.com/view.php?id=12592 |
| 15:27.22 | file | Russell is gone at the moment. |
| 15:27.45 | dawebber | MuffinMan: thanks |
| 15:28.03 | dawebber | what's the best way to get his opinion and get him to weigh in on this? |
| 15:28.52 | file | you can try to grab him on here... but no telling what his schedule is like... |
| 15:30.37 | Juggie | email the dev list |
| 15:34.06 | file | dawebber: what are you testing from? |
| 15:34.55 | dawebber | good ol' phone |
| 15:35.07 | file | so an analog phone hooked up to an FXS port? |
| 15:35.47 | dawebber | either from my cell or a desk phone sitting on another PRI behind a NEC PBX (in either case, two totally separate circuits) |
| 15:35.56 | dawebber | no relation to the PRI asterisk is sitting on |
| 15:36.06 | dawebber | results are the same |
| 15:36.23 | file | so it's a PRI into Asterisk from the telco? |
| 15:36.28 | dawebber | yes |
| 15:37.03 | dawebber | 5ESS switch, Time Warner (the details are in Mantis, hit "View Advanced" under steps to reproduce) |
| 15:37.19 | file | so it would be the inband DTMF detector. |
| 15:38.11 | file | it doesn't seem to be detecting your DTMF in all cases |
| 15:38.24 | dawebber | I think it's an emulation problem |
| 15:38.56 | file | I disagree, like dimas said that log message will be output for the DTMF before emulation even starts |
| 15:39.00 | dawebber | if you look at my original report, you'll see that DTMF injection from the queue back into the DTMF "stream" causes a digit skip |
| 15:39.12 | dawebber | that's after his patch |
| 15:39.23 | dawebber | before that, you can really see the emulation take place |
| 15:39.52 | dawebber | of course, this is just an observation |
| 15:39.57 | dawebber | I'm taking a guess here |
| 15:40.03 | file | what is the Asterisk executing at the time? |
| 15:40.06 | dawebber | based on the output |
| 15:40.35 | dawebber | there is a Cepstral module that plays back a greeting and waits for digits to be pressed |
| 15:40.53 | dawebber | it then returns those digits, one at a time to the calling AGI script |
| 15:41.10 | dawebber | the cepstral module is not the Digium one, in case that matters |
| 15:41.38 | dawebber | but the logs I'm sending are from Asterisk, way before Cepstral gets a hold of them |
| 15:42.04 | file | are the latest tests with or without the patch? |
| 15:42.22 | dawebber | whether Cepstral is playing audio on a channel, or is done playing, the result is the same--digits are skipped--so, it's not a crossover of some sort, I think |
| 15:42.30 | dawebber | with the patch |
| 15:42.59 | *** join/#asterisk-bugs russellb (n=russellb@asterisk/developer-and-stable-maintainer/drumkilla) |
| 15:42.59 | *** mode/#asterisk-bugs [+o russellb] by ChanServ |
| 15:44.08 | dawebber | the very first test dated 05/06 is without the patch (done before dimas made the patch) |
| 15:45.14 | file | I can't look at the Cepstral code to know how it is doing the DTMF stuff... |
| 15:45.32 | file | mumbles |
| 15:46.10 | dawebber | I wrote the code |
| 15:46.14 | dawebber | I can tell you |
| 15:46.21 | dawebber | it's not Digium's module |
| 15:46.36 | *** join/#asterisk-bugs Corydon76-lap (n=Corydon7@pdpc/supporter/bronze/Corydon76-home) |
| 15:46.36 | *** mode/#asterisk-bugs [+o Corydon76-lap] by ChanServ |
| 15:46.39 | dawebber | it's based on the open source app_cepstral with some extra code in it |
| 15:47.10 | dawebber | basically, we are sitting on the wire, catching frames: If frame is DTMF frame, we copy the data from it to a local buffer |
| 15:47.24 | dawebber | this is very simplistic, but that's the idea |
| 15:47.37 | file | so you don't set the flag to do end dtmf only |
| 15:47.47 | russellb | have you verified your bug without your custom module in use? |
| 15:47.52 | russellb | we don't support systems that are modified in any way |
| 15:49.36 | dawebber | russellb: I understand that, but I'm not sure yet, if Cepstral is even relevant here, since the logs I'm presenting are from Asterisk's DTMF module. I do see your point about testing without Cepstral module. |
| 15:49.42 | dawebber | just to eliminate that |
| 15:49.58 | dawebber | I do fail to see how Cepstral would influence DTMF detection code though |
| 15:50.05 | file | everything else in the tree sets the end dtmf only flag causing no emulation to be performed... which would probably (if the issue is emulation related) cause it to be non-existant |
| 15:50.46 | dawebber | file: let me check on your previous question, one sec |
| 15:53.03 | dawebber | file: no I don't set any flags on the channel |
| 15:55.02 | dawebber | sequence: 1) do ast_read() 2) look at frametype 3) if AST_FRAME_DTMF check against a list of digits 4) if interested, copy contents of the subclass to a local buffer 5) free the frame 6) go to 1) |
| 15:55.13 | dawebber | does that make sense? |
| 15:55.46 | file | ast_set_flag(c, AST_FLAG_END_DTMF_ONLY); where c is the channel when entering your application when it wants to look at DTMF |
| 15:55.52 | dawebber | russell: what's the best way to test this in the dialplan? Is there a function that read digits in a loop, so that I can NoOp them? |
| 15:55.56 | file | and ast_clear_flag(c, AST_FLAG_END_DTMF_ONLY); afterwards |
| 15:56.13 | russellb | Read() .. |
| 15:56.13 | file | the Read application, but that test would be skewed because it does what I just told you |
| 15:56.34 | dawebber | file: are you saying I should do that, or are you asking whether I do it? |
| 15:56.51 | file | dawebber: I suggest doing it... and retest |
| 15:56.54 | dawebber | russell: so, what's next best to Read() |
| 15:57.00 | file | without dimas' change |
| 15:57.04 | dawebber | file: ok, sorry just wanted to clarify |
| 15:57.19 | dawebber | I can do that right now, shouldn't take but a minute |
| 15:57.24 | dawebber | well, 5 minutes :) |
| 15:57.36 | file | as long as the inband DTMF detector catches the DTMF, that will work |
| 15:58.30 | file | wonders why dimas thought autoservice would be active |
| 15:59.35 | dawebber | thinks that there was a lot of autoservice discussion going on at the time with several bugs dimas worked on |
| 15:59.44 | dawebber | guesses |
| 16:10.56 | file | M12595 |
| 16:10.58 | MuffinMan | [new] [Asterisk] Channels/chan_zap 0012595: Asterisk stops accepting calls from Zap and responds with fast busy reported by dawebber (Karma: neutral) http://bugs.digium.com/view.php?id=12595 |
| 16:11.12 | dawebber | yes, me also :) |
| 16:11.25 | file | dawebber: as for that the latest code does try to renegotiate to another B channel... and there are very few who know that land... and the primary one is rather busy these days... |
| 16:11.54 | dawebber | is that mattf? |
| 16:11.57 | file | yes |
| 16:12.42 | dawebber | Ah, ok. I worked with him to get code written and tested 2B-channel transfer on 5ESS, that's how I know him |
| 16:12.54 | file | if only we could clone him... |
| 16:13.07 | Qwell | 6 or 8 times.. |
| 16:13.09 | dawebber | well, that's not my department, sorry :) |
| 16:13.46 | file | Qwell: minimum. |
| 16:21.38 | dawebber | ok, changes made and deployed |
| 16:21.52 | dawebber | need another 5 min or so to test various scenarios |
| 16:22.24 | Qwell | M12626 |
| 16:22.26 | MuffinMan | [new] [Asterisk] Applications/app_queue 0012626: Using Addqueumember it's impossible to use the new way to define member reported by dimitripietro (Karma: +1.00) http://bugs.digium.com/view.php?id=12626 |
| 16:22.38 | Qwell | I don't understand what he's saying is broken.. |
| 16:23.09 | dawebber | file: so, Mattf would be the only one to look at that stuff, you think? |
| 16:23.19 | file | dawebber: probably |
| 16:23.42 | file | Qwell: you can't specify what to monitor in AddQueueMember... |
| 16:23.46 | file | I think that is what he means |
| 16:23.59 | file | or it's not documented... |
| 16:24.02 | file | or not working... |
| 16:24.02 | Qwell | oh |
| 16:24.15 | dawebber | file: ok |
| 16:25.23 | file | dance is all I wanna, dance is all I'm needin' |
| 16:25.25 | file | dances |
| 16:25.55 | Qwell | yeah, looks like it's just not documented (and he's doing it wrong) |
| 16:29.20 | *** join/#asterisk-bugs Corydon76-lap (n=Corydon7@pdpc/supporter/bronze/Corydon76-home) |
| 16:29.20 | *** mode/#asterisk-bugs [+o Corydon76-lap] by ChanServ |
| 16:33.41 | dawebber | file: so far, so good |
| 16:33.52 | dawebber | I'm going to post the comments in Mantis |
| 16:34.13 | dawebber | but I'd like to do more testing--as I mentioned in the original steps \ |
| 16:34.26 | dawebber | the code breaks most often when the digits are typed in very quickly |
| 16:35.45 | file | nods |
| 16:43.13 | *** part/#asterisk-bugs codefreeze-lap (n=murf@216.166.159.235) |
| 16:45.58 | *** join/#asterisk-bugs codefreeze-lap (n=murf@216.166.159.235) |
| 16:55.48 | *** join/#asterisk-bugs atis_work (n=atis_wor@193.238.212.171) |
| 17:06.47 | dawebber | file: i documented it in Mantis |
| 17:07.15 | dawebber | I also went ahead and stuck some ast_log statements outputting the flags that are currently set |
| 17:07.33 | dawebber | just so that I can see that the set and clear statements do work |
| 17:09.05 | dawebber | so far, the results are about the same: it works most of the time, but when digits are entered quickly, the second one (always!!) gets lost |
| 17:09.31 | file | so the change did not work? |
| 17:09.59 | dawebber | well, I'd say it has gotten better than with Dimas's patch |
| 17:10.39 | file | there's no additional notes on 12592, yarrrrr |
| 17:12.35 | dawebber | file: interesting thing about Mantis: until you hit "add notes" button, it doesn't add notes even if you type them in LOL |
| 17:12.58 | dawebber | --duh |
| 17:13.35 | dawebber | I though it would just read my mind and submit the notes even if I didn't hit sumbit :) |
| 17:13.42 | file | when it doesn't work with the end change... does it show a DTMF log entry for the DTMF? |
| 17:14.04 | dawebber | yes, let me insert that in the note |
| 17:14.31 | dawebber | file: I removed the ast_set and ast_clear and ran the code |
| 17:14.48 | file | now I'm confused... |
| 17:15.00 | dawebber | it seems that the recognition levels are not as good than with ast_set and ast_clear actually running |
| 17:15.11 | *** join/#asterisk-bugs russellb_ (n=russell@asterisk/developer-and-stable-maintainer/drumkilla) |
| 17:15.11 | *** mode/#asterisk-bugs [+o russellb_] by ChanServ |
| 17:15.13 | file | now I'm even more confused |
| 17:15.16 | dawebber | let me produce the output |
| 17:15.23 | dawebber | maybe it will make more sense |
| 17:15.44 | file | is the latest output you are going to add with or without the flag? |
| 17:17.01 | dawebber | with the flag |
| 17:17.03 | dawebber | it's there now |
| 17:17.05 | file | k |
| 17:17.23 | dawebber | you'll see that the flag is set on line 6 |
| 17:17.26 | dawebber | of the output |
| 17:17.45 | file | looks fine and dandy |
| 17:18.22 | dawebber | I'm assuming that ast_test_flag(chan, AST_FLAG_END_DTMF_ONLY) returns true when it's set |
| 17:18.38 | dawebber | yes, but the sequence is 823229999 |
| 17:19.10 | dawebber | and I'm only seeing 8(2)3229999 |
| 17:19.22 | dawebber | the italicised number in parens is missing |
| 17:19.38 | file | it never reached the core |
| 17:19.58 | dawebber | isn't channel.c the core? |
| 17:20.10 | file | it never went into the core from chan_zap |
| 17:21.16 | dawebber | well, is calling ast_frfree(frame) on the DTMF frame an issue here? |
| 17:21.28 | file | use Read to read in a string of DTMF in your dialplan |
| 17:21.32 | dawebber | ok |
| 17:21.43 | file | just drop it in where Cepstral is called... see if it behaves the same |
| 17:21.54 | dawebber | can the source of that function be used as a guide just to make sure things work right? |
| 17:21.59 | dawebber | just curious |
| 17:22.23 | file | app_read calls an internal API |
| 17:22.50 | Corydon76-lap | and takes care of cleanup for you |
| 17:22.50 | dawebber | ah, ok |
| 17:23.32 | file | if it doesn't work either then I blame the inband DTMF detector not catching your DTMF since it doesn't show up going through the core |
| 17:23.51 | dawebber | i have a Digium TE212P, if that makes a difference |
| 17:24.25 | *** join/#asterisk-bugs oej (n=olle@ns.webway.se) |
| 17:24.36 | dawebber | let me play with Read() and see what the results are |
| 17:24.50 | dawebber | I'll let you guys know shortly and update Mantis also |
| 17:25.35 | dawebber | what baffles me, is that if digits are entered more slowly, all digits make it in |
| 17:26.08 | dawebber | otherwise, it's always the second digit that suffers |
| 17:26.26 | dawebber | wonders: why always second digit? |
| 17:36.57 | dawebber | file: did a test with Read() |
| 17:37.02 | dawebber | results in Mantis |
| 17:37.29 | file | you hit the digit before Read was executing |
| 17:37.48 | dawebber | hmm, ok, let me try again |
| 17:40.22 | dawebber | yes, tried again, waited, seems to have gotten all the digits this time |
| 17:41.09 | dawebber | updated Mantis |
| 17:42.05 | dawebber | so, am I right to think that the issue here is that when digits get emulated, they need to reach the core, the Cepstral is not letting them do so? |
| 17:42.18 | file | no. |
| 17:42.21 | dawebber | or not Cepstral, rather my frame parsing code |
| 17:42.30 | file | the flow is like this: |
| 17:42.31 | dawebber | file: ok, so what am I missing |
| 17:42.39 | file | chan_zap DSP processing -> channel.c ast_read -> you |
| 17:42.48 | dawebber | ok |
| 17:43.02 | dawebber | I guess I'm just not sure where the core comes in |
| 17:43.37 | file | you don't read stuff directly from chan_zap |
| 17:43.43 | file | you read it from the layer in between which is the core |
| 17:43.49 | dawebber | ok |
| 17:44.17 | dawebber | can you point me in the right direction in the API? |
| 17:44.33 | file | when the DTMF passes through the core it outputs a log message, can't stop it unless you disable dtmf logging |
| 17:45.37 | dawebber | ok, I understand. Let me ask the question differently: what is the principal difference between the way Read() does its DTMF reading and I do? |
| 17:45.57 | file | I can't answer that because I don't know your code |
| 17:46.20 | file | the code that app_read uses is ast_app_getdata in main/app.c |
| 17:47.02 | file | which ends up in... ast_readstring_full in main/channel.c, and that uses ast_waitfordigit_full |
| 17:47.32 | dawebber | ok, I see |
| 17:48.33 | dawebber | looks at the doxygen |
| 17:52.53 | dawebber | file: I think you've given me quite a bit of info. So, my choices are: either use the the same API calls that Read() does, or adapt my code to act much like waitstream_core() |
| 17:53.30 | file | nods |
| 17:54.42 | dawebber | ok, thank you. Let me do a bit more digging... |
| 17:57.57 | file | oh, meeting, now |
| 17:58.03 | file | runs around in circles |
| 17:58.38 | dawebber | file: thank you for your help today |
| 17:59.06 | file | are you satisfied with your testing enough that we can close the issue, or shall I leave it open? |
| 18:00.00 | dawebber | file: if you don't mind, let's leave it open until later today or first thing tomorrow, just in case I gain some more insight |
| 18:00.08 | file | aight |
| 18:00.09 | dawebber | and would want to add something |
| 18:00.27 | dawebber | I'll touch base with you later on IRC if that's ok |
| 18:00.45 | dawebber | file, russel: thank you both for your help today |
| 18:00.53 | file | I'm usually always around. |
| 18:01.01 | dawebber | file: ok |
| 18:04.06 | Juggie | hes a silly canadian |
| 18:14.24 | *** join/#asterisk-bugs d1mas (n=chatzill@ip195.117.adsl.wplus.ru) |
| 18:16.04 | d1mas | dawebber: your last test does not show anything - you should wait before FIRST digit but quickly roll over all the digits |
| 18:16.19 | d1mas | this is to make sure Read starts before you start pressing digits |
| 18:18.24 | d1mas | (hello) |
| 18:55.08 | dawebber | d1mas: I have retested |
| 18:55.13 | dawebber | it's in the same note |
| 18:55.45 | d1mas | no, I'm talking about latest part of the last note |
| 18:55.58 | *** join/#asterisk-bugs atis_work (n=atis_wor@193.238.212.171) |
| 18:56.52 | d1mas | dawebber: by "waiting long enough" you mean waiting before first digit or waiting between each one ? |
| 18:57.48 | dawebber | (hi there) back at you |
| 18:58.04 | dawebber | waiting for the console to tell me it's ready to accept digits |
| 18:58.38 | dawebber | once it's ready, I send a stream of digits in, no interruption |
| 18:58.46 | dawebber | is that what you are asking? |
| 18:58.59 | d1mas | yes. |
| 18:59.13 | dawebber | to be more precise: I wait long enough for the first digit |
| 18:59.24 | dawebber | then, send them all in once |
| 18:59.34 | d1mas | dawebber: got it |
| 18:59.54 | dawebber | d1mas: have you been reading the latest on the IRC here? |
| 19:00.14 | dawebber | looks like the issue may not be auto-service related? |
| 19:00.17 | d1mas | dawebber: which means that Cepstral most likely loosing digits because it does not put channel to autoservice |
| 19:00.31 | d1mas | dawebber: No I can not. |
| 19:00.43 | d1mas | dawebber: I only see log after I connected |
| 19:01.10 | dawebber | d1mas: I didn't know if you were hanging around for a while, hence the question |
| 19:01.17 | dawebber | plus some ppl run bots :) |
| 19:01.29 | dawebber | well, see that's where I'm confused about is you say "put channel to autoservice" |
| 19:01.32 | d1mas | some ppl run me :) |
| 19:01.58 | dawebber | LOL! what exactly do you mean? |
| 19:02.00 | d1mas | dawebber: you know what autoservice is, do you? |
| 19:02.10 | dawebber | not exactly |
| 19:02.39 | dawebber | could you explain, plz |
| 19:02.40 | dawebber | ? |
| 19:02.42 | d1mas | dawebber: ok, you HAVE TO constantly read frames from Zap channel otherwise voice frames will be lost |
| 19:02.50 | dawebber | ok, I do that |
| 19:03.01 | dawebber | I sit in a while loop and read frames |
| 19:03.12 | d1mas | dawebber: since some of voice frames contain DTMF "sound" it will lead to losing DTMF digits |
| 19:03.38 | d1mas | dawebber: when you do so, I believe DTMF will be read Ok |
| 19:03.45 | d1mas | dawebber: It is what Read does |
| 19:05.04 | d1mas | dawebber: However, if some application for any reason needs doing some action like database lookup or something like this where is no guaranteed response time, the operation can take 0.0001 sec or it can take 1 sec. You never know |
| 19:05.22 | dawebber | I see |
| 19:05.32 | dawebber | that makes a lot of sense |
| 19:05.34 | d1mas | dawebber: Obviously application is not doing ast_read at such a moment so frames will be lost |
| 19:05.46 | dawebber | right, the code is blocking |
| 19:05.52 | d1mas | dawebber: or more precisely they MAY be lost |
| 19:06.26 | dawebber | so, i need to make sure that the thread reading frames is not blocking on anything |
| 19:06.29 | d1mas | dawebber: This is why an application should put channel to autoservice mode before starting such a blocking operation |
| 19:06.43 | d1mas | dawebber: in this mode special thread will be reading it |
| 19:06.46 | dawebber | ok, how is autoservice activated? |
| 19:06.52 | d1mas | sec |
| 19:07.37 | d1mas | dawebber: basically ast_autoservice_start(chan) + ast_autoservice_stop(chan) |
| 19:07.49 | dawebber | ok, clear enough |
| 19:08.18 | d1mas | dawebber: Look at apps/app_system.c for example |
| 19:08.35 | dawebber | reading russell's comments in SVN on his private branch about that |
| 19:08.49 | dawebber | opens doxygen doc |
| 19:09.56 | dawebber | d1mas: ok, so I can call autoservice early in the game |
| 19:10.03 | dawebber | and stop it late in the game |
| 19:10.07 | dawebber | that's easy enough |
| 19:10.18 | dawebber | is that all that's required? |
| 19:10.20 | d1mas | dawebber: well I'm not sure about your application |
| 19:10.33 | dawebber | right, of course, I'm just thinking loud |
| 19:10.44 | dawebber | but I see the example you provided |
| 19:11.00 | d1mas | dawebber: but in general - yes, you need just surround any blocking action with autoservice start/stop |
| 19:11.13 | dawebber | ok, that's good |
| 19:11.17 | d1mas | dawebber: well, app_system is not the best example |
| 19:11.39 | dawebber | ok, what are the downsides of using autoservice? |
| 19:11.47 | dawebber | (if there are any)? |
| 19:11.59 | d1mas | dawebber: because it does this only once. You may need doing this multiple times depending on your application. Let me explein.... |
| 19:13.15 | dawebber | ok |
| 19:13.35 | d1mas | dawebber: when asterisk looks up the number you already dialed so far against dialplan + all the DUNDi/realtime/whatever switches, it can take a while (especially dundi). This is why asterisk puts channel into autoservice before doing such a lookup and then continues reading more digits (optionally). |
| 19:13.52 | dawebber | ok |
| 19:13.58 | d1mas | dawebber: so the autoservice is not used once per application but the channel is constantly switched back and forth |
| 19:14.05 | d1mas | one sec |
| 19:15.33 | d1mas | take a look at how pbx_find_extension (pbx.c) works |
| 19:17.26 | dawebber | looking |
| 19:20.04 | dawebber | d1mas: so, it only goes to autoservice to when it is about to read some frames on the wire, otherwise, it stays single-threaded, correct? |
| 19:21.23 | d1mas | dawebber: well, technically your application always stays single threaded. It just delegates handling channel to some "3rd party" :) thread when your single thread is abot to query some external system |
| 19:21.41 | dawebber | right |
| 19:21.56 | dawebber | so, putting that in perspective: |
| 19:22.09 | dawebber | I'm sitting on the wire, catching frames |
| 19:22.56 | dawebber | once I hit frametype of AST_FRAME_DTMF |
| 19:23.24 | dawebber | I go to autoservice, do what i need to do outside and then cancel autoservice |
| 19:23.28 | dawebber | correct? |
| 19:23.42 | d1mas | what do you do with DTMF frames in your application? |
| 19:25.08 | dawebber | well, here's what is going on |
| 19:25.40 | dawebber | I'm catching audio from a TTS engine, in chunks and writing it to an fd on the channel. |
| 19:25.56 | dawebber | at the same time, I'm listening for the user to hit some DTMF digit |
| 19:26.04 | d1mas | aha... |
| 19:26.29 | dawebber | if DTMF digit is valid in this context (valid escape digit), I interrupt, streaming, set some vars and exit the module |
| 19:27.05 | dawebber | now, the main procedure of the frame reading code, basically is a loop that takes a frame and looks at the frametype |
| 19:27.57 | d1mas | dawebber: got it. Well, things may be little complex here. First - how do you check if digit is a valid ? |
| 19:28.09 | dawebber | if the frametype is anything but DTMF, I'm not interested, so I ast_frfree() it and go on |
| 19:28.11 | d1mas | (in a given context) |
| 19:28.17 | dawebber | well, that's easy |
| 19:28.39 | dawebber | I get a string of escape digits as a parameter from the dialplan |
| 19:28.55 | dawebber | (really, it's an AGI script that's calling my module, but that's irrelevant) |
| 19:29.08 | dawebber | so, if the digit is in the list, it's valid |
| 19:29.17 | d1mas | dawebber: I'm trying to understand why extension lookup is blocking operation at all |
| 19:29.58 | dawebber | for instance, if the message is "Press 1 to go the next menu", and you press 2, the audio will keep on streaming |
| 19:30.06 | d1mas | dawebber: because _normal_ Asterisk extension lookup already puts channel to autoservice |
| 19:30.10 | dawebber | but as soon as you hit 1, I stop |
| 19:30.20 | dawebber | I don't lookup extensions |
| 19:30.30 | dawebber | this is an IVR |
| 19:30.34 | dawebber | let me give you an example |
| 19:30.36 | d1mas | I understand |
| 19:30.39 | d1mas | but |
| 19:30.45 | dawebber | you call the bank and you get asked for card number |
| 19:30.54 | dawebber | it's 16 digits |
| 19:31.00 | dawebber | so, I need 16 DTMF digits |
| 19:31.12 | d1mas | you are saying "if DTMF digit is valid in this context (valid escape digit), I interrupt, streaming" |
| 19:31.44 | dawebber | the word "context" is ambivalent here. What I should have said is: " if it's valid for a given menu". I apologize |
| 19:31.59 | dawebber | this is nothing to do with Asterisk's contexts |
| 19:33.06 | dawebber | so, my question is: do i put the channel in autoservice as soon as I enter my while loop or only when I got my first DTMF frame and need to check it against the list of valid frames? |
| 19:33.21 | d1mas | so, do you really have your own application (C source) ? or you are duing some sort of AGI ? |
| 19:33.37 | d1mas | neither! |
| 19:34.21 | d1mas | duing=doing |
| 19:35.32 | dawebber | I have a module called app_cepstraltts |
| 19:35.37 | dawebber | it's C |
| 19:35.52 | d1mas | ok |
| 19:36.10 | dawebber | it registers an AGI command dynamically that looks like this: CepstralTTS("mystring","escapedigits") |
| 19:36.40 | dawebber | so, the module can be used from CLI or AGI |
| 19:37.47 | dawebber | pretty twisted, huh? |
| 19:37.53 | d1mas | dawebber: not really |
| 19:38.00 | d1mas | dawebber: however there is a problem |
| 19:38.04 | dawebber | yes |
| 19:38.10 | dawebber | what is it? |
| 19:39.13 | d1mas | dawebber: Let me clarify one more thing - the CepstralTTS("mystring","escapedigits") is supposed to read "mystring" to caller and read some digits only right? the IVR itself is done not insede the application but using a dialplan (or AGI), right ? |
| 19:40.04 | dawebber | correct |
| 19:40.38 | d1mas | dawebber: and how do you tell the application how many digits you need to read? or it is only one per one TTS execution ? |
| 19:41.06 | dawebber | you can forget about the IVR altogether, and think of a DialPlan string looking like this: xxxxxxxx,n,Cepstral("mystring","mydigits") |
| 19:41.25 | dawebber | there could be any number of digits |
| 19:41.48 | dawebber | for instance, if you are asked to enter your telephone number, only 0...9 are valid |
| 19:41.53 | d1mas | dawebber: mydigits is the list of accepted digits so pressing ANY of them stops TTS ? |
| 19:42.03 | dawebber | correct |
| 19:42.28 | dawebber | once I get a valid digit, I stop TTS, clean up code, and exit the module |
| 19:42.31 | d1mas | dawebber: what I do not understand is how to enter telephone number containing more than 1 digit :) |
| 19:42.36 | dawebber | ok, easy |
| 19:42.43 | dawebber | call the command 9 times |
| 19:42.44 | dawebber | <PROTECTED> |
| 19:43.08 | dawebber | 10 actually for North American numbers |
| 19:43.26 | d1mas | okay. And there is a problem :) |
| 19:43.56 | d1mas | asterisk won't be collecting these digits into some kind of buffer while you are not reading them |
| 19:45.04 | d1mas | I will put it another way: |
| 19:45.33 | dawebber | yes, you are right. I just talked to the IVR script developer |
| 19:45.39 | d1mas | if you do Playback(here goes long message) and then Read. And user presses a digit during playback - it wont be read by Read |
| 19:46.04 | dawebber | here's what's going on |
| 19:46.23 | dawebber | he's calling my command the first time, gets a digit back if a user pressed something |
| 19:47.04 | dawebber | then he calls GetDigits(), which calls waitfordigit |
| 19:48.05 | dawebber | I think |
| 19:48.08 | dawebber | let me check the dox |
| 19:50.14 | dawebber | yes |
| 19:50.24 | dawebber | it's calling ast_waitfordigit_full |
| 19:50.36 | d1mas | what is GetDigits? my asterisk does not have such an app |
| 19:50.43 | d1mas | I have Read |
| 19:50.53 | dawebber | look at res_agi.c |
| 19:51.07 | dawebber | line 779 |
| 19:51.36 | d1mas | agi... (have to warn you I have never ever used it) :) |
| 19:51.44 | dawebber | ast_waitfordigit_full doesn't use autoservice |
| 19:51.50 | dawebber | that's ok |
| 19:52.01 | dawebber | you can forget about the AGI |
| 19:52.09 | dawebber | it's what it's calling under the covers |
| 19:52.22 | dawebber | if you look at res_agi.c you'll see what I mean |
| 19:52.32 | dawebber | file was talking about that |
| 19:52.38 | d1mas | looks like you can forget about autoservice :) |
| 19:52.42 | dawebber | yes |
| 19:53.00 | dawebber | they are only using AST_FLAG_END_DTMF_ONLY |
| 19:53.07 | dawebber | setting the flag and going forward |
| 19:53.12 | d1mas | autoservice is needed when SINGLE (long running) application needs sometimes doing some long blocking calls |
| 19:53.27 | dawebber | right |
| 19:53.44 | dawebber | but here's the paradox |
| 19:53.47 | d1mas | you have bunch of applications running one after another in the loop |
| 19:54.04 | dawebber | my question is this: |
| 19:54.45 | dawebber | if the first digit is getting read by CepstralTTS, why is it that the second digit always gets lost? |
| 19:55.11 | dawebber | the second digit is the one read via ast_waitfordigits_full() |
| 19:55.31 | dawebber | so, my assumption is that Cepstral module needs autoservice |
| 19:55.35 | d1mas | one of reasons: |
| 19:55.54 | dawebber | otherwise, it "eats" the second DTMF frame before the core gets hold of it |
| 19:55.58 | d1mas | 1. too much time passes between the first digit is read and the next time ast_read is called on the channel |
| 19:56.28 | d1mas | 2. somebody does ast_read _before_ GetDigits and eats your digit |
| 19:56.33 | *** join/#asterisk-bugs atis_work (n=atis_wor@193.238.212.171) |
| 19:56.54 | d1mas | from your logs it looks like #1 is the case |
| 19:56.59 | dawebber | I think so two |
| 19:57.03 | dawebber | two=too |
| 19:57.09 | dawebber | sorry, it's Monday :) |
| 19:57.23 | dawebber | 1) is the most likely scenario |
| 19:57.45 | dawebber | could it be that too much time passes between the time I get the frame and call ast_frframe on it? |
| 19:58.05 | dawebber | if I can just surround that piece of code with autoservice, this might be solving the issue |
| 19:58.36 | dawebber | because in my application, I only care for the first digit if it's in my "valid" list |
| 19:58.52 | dawebber | that way, any subsequent frames will get passed on down |
| 19:59.59 | d1mas | can you do a simple test like two line dialplan - Cepstral + Read ? |
| 20:00.21 | dawebber | I can, yes |
| 20:00.28 | dawebber | what's the goal? |
| 20:01.07 | d1mas | will it miss a digit or not |
| 20:01.14 | d1mas | it should NOT |
| 20:01.58 | d1mas | if it does - it means either Cepstral takes to much time to finish or it reads some more frames after getting the digit |
| 20:03.13 | dawebber | ok, if it does --then I have two options : 1) ether change my code to not do any work while checking the frames |
| 20:03.28 | dawebber | or 2) make sure I don't read any more frames |
| 20:05.35 | dawebber | would you agree? |
| 20:07.22 | d1mas | hmm... I'm lost again. What work your code does when checking the frames??? |
| 20:07.47 | d1mas | I thought it is something like substring search. It is NOTHING |
| 20:08.44 | dawebber | correct |
| 20:08.58 | dawebber | well, it writes a line of code to asterisk log |
| 20:09.07 | d1mas | still nothing |
| 20:09.11 | dawebber | I thought maybe that's what you mean by "too long" |
| 20:09.23 | d1mas | can you paste piece of code to pastebin ? |
| 20:09.47 | dawebber | yes, I actually just made a change to free the frame immediately |
| 20:09.53 | dawebber | and it still didn't help |
| 20:10.06 | dawebber | so, I think 2) applies form your list above |
| 20:10.16 | d1mas | it is not important |
| 20:11.23 | dawebber | ok |
| 20:11.29 | dawebber | so, let me paste some code |
| 20:11.46 | d1mas | you know pastebin ? |
| 20:12.27 | dawebber | I do now :) |
| 20:12.37 | dawebber | pastebin.com, correct? |
| 20:12.46 | Corydon76-lap | dot-ca is better |
| 20:13.01 | Corydon76-lap | dot-ca actually support Asterisk dialplan, for instance |
| 20:13.13 | d1mas | oh |
| 20:13.28 | d1mas | syntax highlight you mean? |
| 20:13.52 | Corydon76-lap | Right |
| 20:14.01 | dawebber | ok, so which one? |
| 20:14.27 | Qwell | pastebin.ca |
| 20:14.35 | dawebber | ok |
| 20:16.16 | dawebber | http://pastebin.ca/1016179 |
| 20:17.27 | d1mas | omg |
| 20:18.31 | dawebber | that bad? |
| 20:18.48 | d1mas | dawebber: why you are checking DTMF flags at all? _application_ should not care about them |
| 20:19.02 | dawebber | something that file was talking about |
| 20:19.13 | dawebber | setting AST_FLAG_END_DTMF_ONLY |
| 20:19.25 | dawebber | I wanted to see whether they are set by default |
| 20:19.42 | dawebber | i just added that a bit ago |
| 20:19.50 | dawebber | we were talking about these flags |
| 20:20.00 | dawebber | now, coming back to the omg? |
| 20:20.02 | d1mas | dawebber: I do not think you need it. However it is not the problem. |
| 20:20.08 | dawebber | is it really that bad? |
| 20:20.23 | dawebber | I'm noob and all, but I figured this wasn't a complete disaster |
| 20:20.25 | dawebber | :) |
| 20:21.10 | d1mas | dawebber: another one (again not THE probjem, I just notices it) - isn't args.escapeDigits a char* ? |
| 20:22.05 | dawebber | yes |
| 20:22.37 | dawebber | and yes, there are better ways of checking a string for prsence of a character |
| 20:22.40 | d1mas | then sizeof() for the for loop is a bad idea |
| 20:22.44 | d1mas | you need strlen() |
| 20:22.51 | dawebber | yes, i know |
| 20:23.31 | dawebber | there was some other code here and I was doing things in a loop to test something else, unrelated---you are absolutely correct, strlen and strtok are better choices |
| 20:24.01 | d1mas | Ok, let me check original swift cpde to get idea how application shuts down |
| 20:24.13 | dawebber | ashamed of showing noobness |
| 20:25.15 | dawebber | http://pastebin.ca/1016197 |
| 20:25.19 | dawebber | check the top part |
| 20:26.45 | dawebber | so, if there is any data to feed down the fd and the immediate_exit is set, call swift_port_stop |
| 20:27.00 | dawebber | otherwise close the port and the engine |
| 20:27.40 | d1mas | dawebber: do you do it in the loop? |
| 20:27.44 | dawebber | nope |
| 20:28.05 | d1mas | dawebber: can you show the whole _exec ? |
| 20:28.21 | dawebber | sure hang on |
| 20:31.54 | d1mas | it can be just a locking issue |
| 20:32.47 | d1mas | I mean it takes time to grab a lock to signal exit and because of this exisitng takes time |
| 20:33.17 | d1mas | during which you are not reading channel. Which is hard to check without the code :) |
| 20:33.26 | dawebber | http://pastebin.ca/1016205 |
| 20:33.48 | dawebber | hope you like spaghetti |
| 20:34.16 | dawebber | I've butchered the code in many places, just trying to fogure out some of this stuff, and why it wasn't working |
| 20:34.19 | d1mas | used to work with it :) |
| 20:35.28 | dawebber | ok, when I grow up, I will write clean Asterisk code, I promise :) |
| 20:37.59 | d1mas | 1. you need to put the channel into autoservice while you initalizing swift and stop autoservice before you about to read digits |
| 20:38.21 | d1mas | otherwise anything user presses during that "setup" phase may be lost |
| 20:38.47 | dawebber | ok |
| 20:38.50 | Corydon76-lap | Not to distract too much from your efforts, but as this channel is meant for discussion and coordination of filed Asterisk bugs, could you move your discussion to another channel or to private message, please? |
| 20:38.51 | d1mas | do NOT forget stopping autoservice in the case of any premature return btw |
| 20:39.11 | d1mas | ok, sorry |
| 20:39.37 | dawebber | I was actually about to ask whether everyone else is tired of us |
| 20:39.38 | dawebber | sorry |
| 20:40.18 | Corydon76-lap | Not a problem; I don't want to stop you from writing Asterisk apps, just move to a more appropriate forum. ;-) |
| 20:55.41 | d1mas | Corydon76: btw, although the issue is with 3rd party application, the very first log in the 12592 is clearly a bug in the Asterisk DTMF emulation code |
| 20:56.13 | *** join/#asterisk-bugs atis_work (n=atis_wor@193.238.212.171) |
| 20:56.43 | d1mas | the one in "Steps To Reproduce " |
| 21:28.47 | *** join/#asterisk-bugs implicit (n=implicit@ip72-211-213-26.oc.oc.cox.net) |
| 21:28.47 | *** mode/#asterisk-bugs [+o implicit] by ChanServ |
| 21:56.12 | *** part/#asterisk-bugs codefreeze-lap (n=murf@216.166.159.235) |
| 21:56.36 | *** join/#asterisk-bugs codefreeze-lap (n=murf@216.166.159.235) |
| 22:16.56 | *** part/#asterisk-bugs dawebber (n=dawebber@209.136.161.135) |
| 23:29.51 | *** join/#asterisk-bugs fakhir (n=fakhir@unaffiliated/fakhir) |