[Home]

Summary:ASTERISK-26481: FILE function grabs garbage along with read data when target line has no newline
Reporter:Jonathan Harris (lardconcepts)Labels:dialplan file len patch string variables
Date Opened:2016-10-18 06:40:58Date Closed:2019-11-18 10:21:05.000-0600
Priority:MajorRegression?
Status:Closed/CompleteComponents:Functions/General
Versions:14.0.1 14.1.0 17.0.0 Frequency of
Occurrence		Constant
Related
Issues:
Environment:Linux 4.4.0-38-generic #57-Ubuntu SMP Tue Sep 6 15:42:33 UTC 2016 x86_64 x86_64 x86_64 GNU/Linux and also Ubuntu 19.10 (GNU/Linux 5.3.0-19-generic x86_64)Attachments:( 0) ASTERISK-26481_workaround_fixes_only_half_the_code.patch
( 1) filereader_code.txt
( 2) filereader_output.txt
Description:*Edited by Rusty Newton*

The description and comments were a little confusing. Here is working dialplan to reproduce the issue:

{noformat}
exten => 5,1,Verbose(Context: ${CONTEXT} Exten:${EXTEN})
   same => n,Set(featurefile=/etc/asterisk/testfile.txt)
   same => n,Set(myList=A,AB,ABC,ABCD,ABCDE,ABCDEF,ABCDEFG,ABCDEFGH)
   same => n,While($["${SET(rawVar=${SHIFT(myList)})}" != ""])
   same => n,Verbose(rawVar is set to ${rawVar})
   same => n,Set(FILE(${featurefile})=${rawVar})
   same => n,Set(fileVar=${FILE(${featurefile},0,1,l,u)})
   same => n,Set(hexDump=${SHELL(hd ${featurefile})})
   same => n,Verbose(Before file: ---${rawVar}--- len ${LEN(${rawVar})} after file: ---${fileVar}--- LEN ${LEN(${fileVar})} hexdump:${hexDump})
   same => n,EndWhile()
   same => n,Hangup()
{noformat}

When FILE reads the file with more than one character it grabs garbage.

{noformat}

newtonr-laptop*CLI> channel originate LOCAL/5@from-internal application wait 600
   -- Called 5@from-internal
   -- Executing [5@from-internal:1] Verbose("Local/5@from-internal-00000018;2", "Context: from-internal Exten:5") in new stack
Context: from-internal Exten:5
   -- Executing [5@from-internal:2] Set("Local/5@from-internal-00000018;2", "featurefile=/etc/asterisk/testfile.txt") in new stack
   -- Executing [5@from-internal:3] Set("Local/5@from-internal-00000018;2", "myList=A,AB,ABC,ABCD,ABCDE,ABCDEF,ABCDEFG,ABCDEFGH") in new stack
   -- Executing [5@from-internal:4] While("Local/5@from-internal-00000018;2", "1") in new stack
   -- Executing [5@from-internal:5] Verbose("Local/5@from-internal-00000018;2", "rawVar is set to A") in new stack
rawVar is set to A
   -- Executing [5@from-internal:6] Set("Local/5@from-internal-00000018;2", "FILE(/etc/asterisk/testfile.txt)=A") in new stack
   -- Executing [5@from-internal:7] Set("Local/5@from-internal-00000018;2", "fileVar=A") in new stack
   -- Executing [5@from-internal:8] Set("Local/5@from-internal-00000018;2", "hexDump=00000000  41                                                |A|
   -- 00000001
   -- ") in new stack
   -- Executing [5@from-internal:9] Verbose("Local/5@from-internal-00000018;2", "Before file: ---A--- len 1 after file: ---A--- LEN 1 hexdump:00000000  41                                                |A|
   -- 00000001
   -- ") in new stack
Before file: ---A--- len 1 after file: ---A--- LEN 1 hexdump:00000000  41                                                |A|
00000001

   -- Executing [5@from-internal:10] EndWhile("Local/5@from-internal-00000018;2", "") in new stack
   -- Executing [5@from-internal:4] While("Local/5@from-internal-00000018;2", "1") in new stack
   -- Executing [5@from-internal:5] Verbose("Local/5@from-internal-00000018;2", "rawVar is set to AB") in new stack
rawVar is set to AB
   -- Executing [5@from-internal:6] Set("Local/5@from-internal-00000018;2", "FILE(/etc/asterisk/testfile.txt)=AB") in new stack
   -- Executing [5@from-internal:7] Set("Local/5@from-internal-00000018;2", "fileVar=ABU��") in new stack
[Oct 27 17:18:45] ERROR[12266][C-00000019]: json.c:825 ast_json_vpack: Error building JSON from '{s: s, s: s}': Invalid UTF-8 string.
[Oct 27 17:18:45] ERROR[12266][C-00000019]: stasis_channels.c:773 ast_channel_publish_varset: Error creating message
   -- Executing [5@from-internal:8] Set("Local/5@from-internal-00000018;2", "hexDump=00000000  41 42                                             |AB|
   -- 00000002
   -- ") in new stack
   -- Executing [5@from-internal:9] Verbose("Local/5@from-internal-00000018;2", "Before file: ---AB--- len 2 after file: ---ABU��--- LEN 6 hexdump:00000000  41 42                                             |AB|
   -- 00000002
   -- ") in new stack
Before file: ---AB--- len 2 after file: ---ABU��--- LEN 6 hexdump:00000000  41 42                                             |AB|
00000002

   -- Executing [5@from-internal:10] EndWhile("Local/5@from-internal-00000018;2", "") in new stack
{noformat}
Comments:By: Asterisk Team (asteriskteam) 2016-10-18 06:40:59.101-0500

Thanks for creating a report! The issue has entered the triage process. That means the issue will wait in this status until a Bug Marshal has an opportunity to review the issue. Once the issue has been reviewed you will receive comments regarding the next steps towards resolution.

A good first step is for you to review the [Asterisk Issue Guidelines|https://wiki.asterisk.org/wiki/display/AST/Asterisk+Issue+Guidelines] if you haven't already. The guidelines detail what is expected from an Asterisk issue report.

Then, if you are submitting a patch, please review the [Patch Contribution Process|https://wiki.asterisk.org/wiki/display/AST/Patch+Contribution+Process].
By: Walter Doekes (wdoekes) 2016-10-21 02:52:45.397-0500

Your problem with LEN is (*not-a-bug*) this:
{noformat}
${LEN(fileVar)}
{noformat}
should be:
{noformat}
${LEN(${fileVar})}
{noformat}
because:
{noformat}
[Synopsis]
Return the length of the string given.

[Description]
Example: ${LEN(example)} returns 7

[Syntax]
LEN(string)
{noformat}
By: Walter Doekes (wdoekes) 2016-10-21 03:16:16.618-0500

As for the FILE problem, this code is not going to win any code beauty pageant:
{code}
                       if (fread(fbuf, 1, sizeof(fbuf), ff) < sizeof(fbuf) && !feof(ff)) {
                               ast_log(LOG_ERROR, "Short read?!!\n");
                               fclose(ff);
                               return -1;
                       }
                       for (pos = fbuf; pos < fbuf + sizeof(fbuf); pos++) {
                               LINE_COUNTER(pos, format, current_length);

                               if (current_length == length) {
                                       length_offset = i + (pos - fbuf) + 1;
                                       break;
                               }
                       }
                       ast_debug(3, "length_offset=%" PRId64 ", length_offset - i=%" PRId64 "\n", length_offset, length_offset - i);
                       ast_str_append_substr(buf, len, fbuf, (length_offset >= 0) ? length_offset - i : (flength > i + sizeof(fbuf)) ? sizeof(fbuf) : flength - i);

                       if (length_offset >= 0) {
                               break;
                       }
{code}
I suspect that this code assumes that it has found a line, including a newline. But you didn't write a newline into the file, so it probably gets some stack garbage from fbuf instead.

Try {{ASTERISK-26481_workaround_fixes_only_half_the_code.patch}}
By: Jonathan Harris (lardconcepts) 2016-10-21 03:27:07.568-0500

Oops, well spotted. but do you mind testing this updated code as I'm still getting incorrect LEN here:

https://gist.github.com/lardconcepts/2b6eb371748c4bb2202082a44e5be871
By: Jonathan Harris (lardconcepts) 2016-10-21 03:37:47.750-0500

Thanks - re patch, running patches is a little beyond me. However, I would hasten to point out that the loop I ran was just to generate files of varying lengths to demonstrate that it appears at consistent lengths.

Regarding newlines, you cannot have a newline in a file when used to get a variable by FILE, because it always adds in the newline, even if FILE is only told to get 1 line, and given the correct file format.

In other words, unless you either have exactly one line with no line return, OR you use the workaround from the mailing list, terminate the line with "," and use CUT. then you can never check on a variable returned by FILE as it always includes newline character. Does that make sense?

Can I just check if that is also the intended behaviour?
By: Walter Doekes (wdoekes) 2016-10-21 08:38:21.007-0500

{{$\{LEN(rawVar)}}{{}}}...
By: Jonathan Harris (lardconcepts) 2016-10-21 10:42:22.590-0500

Oh damn, sorry. I'm incredibly behind , tired and stressed with this FILE thing, and you're right.

HOWEVER... that first LEN is immaterial, it's the second one which has the correct format, but always puts out 6.

In other words,
{code}"after file: ---${fileVar}--- LEN ${LEN(${fileVar})}" {code} (<< correct, agreed?) gives (part of loop output shown)

{code}
"Before file: ---1--- len 1 after file: ---1FEc--- LEN 6"
"Before file: ---ABCDE--- len 5 after file: ---ABCD--- LEN 6"
{code}

So above we see that 1 character is now 4 and 5 characters is now 4, both measured as 6. And even if I HAD got the VAR format wrong, "fileVar" is 7 characters now 6 :)

Notice that now the random blob character has changed to 3 extra letters. Which kind of fits in with what you said about " it probably gets some stack garbage from fbuf instead".
By: Rusty Newton (rnewton) 2016-10-27 17:23:12.377-0500

I don't see any issue with LEN. LEN seems to just be giving various lengths due to the garbage coming in with FILE.

I'm editing the description for clarity and going to open this issue up. If you find an issue with LEN please open a new issue and we can discuss it separately there. We don't want to muddle the issue by discussing too many issues on one ticket.
By: Jonathan Harris (lardconcepts) 2017-03-24 10:00:10.586-0500

Although I've not seen any progress on this or detail in the latest release, it appears, from basic testing, that this issue may be resolved in 14.4.0 RC1.
By: Rusty Newton (rnewton) 2017-03-24 10:38:35.149-0500

Interesting... if you test further and find it is resolved then let us know.
By: Jonathan Harris (lardconcepts) 2017-03-24 16:01:40.226-0500

I have attached the code and output which previously failed.
As you can see, this is what is happening on the latest RC build.
But, I must be honest and say I have not tested it since November, so cannot say for sure that this was not fixed earlier.
Either way, as far as I can see, it's OK now.
By: Jonathan Harris (lardconcepts) 2019-10-29 04:47:38.433-0500

October 2019, Asterisk 17.0, this is still happening

File is a single line unix encoded file, with  "1," (no quote marks)

hexdump output is as follows (sorry, no idea why code blocks aren't working)

```
0000000 2c31
0000002
```

dialplan is

```
   same => n(skipto),Set(unfilteredfeat=${FILE(${scanPath}/skipto.txt,0,1,l,u)})
   same => n,Set(feature=${SHIFT(unfilteredfeat)})
   same => n,Verbose(1,feature is ${feature} unfilteredfeat is ${unfilteredfeat})
```

Console log output is

```
   -- Executing [s@root:40] Set("Local/s@root-00000011;2", "unfilteredfeat=1,▒=") in new stack
[Oct 29 09:36:15] ERROR[2134][C-00000012]: json.c:607 ast_json_vpack: Error building JSON from '{s: s, s: s}': Invalid UTF-8 string.
[Oct 29 09:36:15] ERROR[2134][C-00000012]:   Got 11 backtrace records
# 0: /usr/sbin/asterisk(ast_json_pack+0xa5) [0x5627588a7f45]
# 1: /usr/sbin/asterisk(ast_channel_publish_varset+0x30) [0x562758937820]
# 2: /usr/sbin/asterisk(pbx_builtin_setvar_helper+0x148) [0x5627588e8e78]
# 3: /usr/sbin/asterisk(pbx_builtin_setvar+0x119) [0x5627588e9209]
# 4: /usr/sbin/asterisk(pbx_exec+0x158) [0x5627588dedf8]
# 5: /usr/sbin/asterisk(+0x137479) [0x5627588d3479]
# 6: /usr/sbin/asterisk(+0x139134) [0x5627588d5134]
# 7: /usr/sbin/asterisk(+0x13a7a1) [0x5627588d67a1]
# 8: /usr/sbin/asterisk(+0x1bd598) [0x562758959598]
# 9: /lib/x86_64-linux-gnu/libpthread.so.0(+0x9669) [0x7fa95fd1b669]
#10: /lib/x86_64-linux-gnu/libc.so.6(clone+0x43) [0x7fa95fa9f323]

[Oct 29 09:36:15] ERROR[2134][C-00000012]: stasis_channels.c:1161 ast_channel_publish_varset: Error creating message
[Oct 29 09:36:15] ERROR[2134][C-00000012]: json.c:607 ast_json_vpack: Error building JSON from '{s: s, s: s}': Invalid UTF-8 string.
[Oct 29 09:36:15] ERROR[2134][C-00000012]:   Got 12 backtrace records
# 0: /usr/sbin/asterisk(ast_json_pack+0xa5) [0x5627588a7f45]
# 1: /usr/sbin/asterisk(ast_channel_publish_varset+0x30) [0x562758937820]
# 2: /usr/sbin/asterisk(pbx_builtin_setvar_helper+0x148) [0x5627588e8e78]
# 3: /usr/lib/asterisk/modules/func_strings.so(+0x64c0) [0x7fa93fd054c0]
# 4: /usr/sbin/asterisk(ast_func_read+0x326) [0x5627588e35b6]
# 5: /usr/sbin/asterisk(pbx_substitute_variables_helper_full+0x282) [0x5627588e7cc2]
# 6: /usr/sbin/asterisk(+0x137445) [0x5627588d3445]
# 7: /usr/sbin/asterisk(+0x139134) [0x5627588d5134]
# 8: /usr/sbin/asterisk(+0x13a7a1) [0x5627588d67a1]
# 9: /usr/sbin/asterisk(+0x1bd598) [0x562758959598]
#10: /lib/x86_64-linux-gnu/libpthread.so.0(+0x9669) [0x7fa95fd1b669]
#11: /lib/x86_64-linux-gnu/libc.so.6(clone+0x43) [0x7fa95fa9f323]

[Oct 29 09:36:15] ERROR[2134][C-00000012]: stasis_channels.c:1161 ast_channel_publish_varset: Error creating message
   -- Executing [s@root:42] Set("Local/s@root-00000011;2", "feature=1") in new stack
   -- Executing [s@root:43] Verbose("Local/s@root-00000011;2", "1,feature is 1 unfilteredfeat is ▒=") in new stack
feature is 1 unfilteredfeat is ▒=
```

By: Friendly Automation (friendly-automation) 2019-11-18 09:57:26.142-0600

Change 13175 merged by George Joseph:
func_env: Prevent FILE() from reading garbage at end-of-file

[https://gerrit.asterisk.org/c/asterisk/+/13175|https://gerrit.asterisk.org/c/asterisk/+/13175]
By: Jonathan Harris (lardconcepts) 2019-11-18 10:19:38.087-0600

Thanks Team!
By: Asterisk Team (asteriskteam) 2019-11-18 10:19:38.406-0600

This issue has been reopened as a result of your commenting on it as the reporter. It will be triaged once again as applicable.
By: Friendly Automation (friendly-automation) 2019-11-18 10:43:28.522-0600

Change 13200 merged by Friendly Automation:
func_env: Prevent FILE() from reading garbage at end-of-file

[https://gerrit.asterisk.org/c/asterisk/+/13200|https://gerrit.asterisk.org/c/asterisk/+/13200]
By: Friendly Automation (friendly-automation) 2019-11-18 12:41:48.365-0600

Change 13201 merged by Friendly Automation:
func_env: Prevent FILE() from reading garbage at end-of-file

[https://gerrit.asterisk.org/c/asterisk/+/13201|https://gerrit.asterisk.org/c/asterisk/+/13201]
By: Friendly Automation (friendly-automation) 2019-11-18 13:06:32.929-0600

Change 13199 merged by George Joseph:
func_env: Prevent FILE() from reading garbage at end-of-file

[https://gerrit.asterisk.org/c/asterisk/+/13199|https://gerrit.asterisk.org/c/asterisk/+/13199]