Segfaults on Linux

[Tom Chiverton]

Although I believe our Apache is serving pages correctly, the error log has severalk entries an hour like
*** Error in `/usr/sbin/httpd': free(): invalid next size (fast): 0x00005634f579f2b0 ***

I have extracted a core dump for when this happens, and it seems to point at modcfml :

#16 0x00007f300acdf22d in malloc_printerr (ptr=<optimized out>, str=0x7f300ade1450 "free(): invalid next size (fast)", action=3) at malloc.c:4976
#17 _int_free (av=0x7f300b01d760 <main_arena>, p=<optimized out>, have_lock=0) at malloc.c:3804
#18 0x00007f3000a75c88 in modcfml_handler () from /etc/httpd/modules/mod_cfml.so
#19 0x00005634f31c91d0 in ap_run_handler (r=0x5634f559e6f0) at /usr/src/debug/httpd-2.2.31/server/config.c:157

The SHA1 hash of my mod_cfml.so is
50a8ba8de0a908d3526e26eddf0475b34e7fe4fc  mod_cfml.so
and dated the 26th September, which I believe to be the most recent version.

I can't find any matching bug reports.

Is this enough information to be useful in debugging, or do I need to build my own, maybe being sure to include the line numbers somehow ?

Tom

[Jordan Michaels]

I would recommend compiling directly for sure. I assume that this instance of mod_cfml was created by the installer? The scripts that the installer uses attempt to match supported systems and bit-types, but that doesn't mean every compile will be 100% compatible. Out of curiosity, what flavor of Linux are you installing this on to?

The list of pre-compiled versions of mod_cfml that ship with the installer are here:

https://github.com/utdream/CFML-Installers/tree/master/lucee/linux/sys/mod_cfml

Let us know if a custom-compile helps the situation.

Kind regards,
Jordan Michaels

--
You received this message because you are subscribed to the Google Groups "mod_cfml" group.
To unsubscribe from this group and stop receiving emails from it, send an email to mod_cfml+u...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[Paul Klinkenberg]

Hi Tom,

Thanks for the report. As the author of this piece of mod_cfml, I will check the code, and try to reproduce the error.

Like Jordan asked, what flavor of Linux are you using?
Also, do you know what the http request looked like? Eg. GET/POST, exact url (hostname can be omitted if you want), incoming headers... Was there any rewriting done already on the request?

Kind regards,

Paul Klinkenberg

[Tom Chiverton]

On Monday, October 19, 2015 at 8:29:07 PM UTC+1, Paul Klinkenberg wrote:

Hi Tom,

Thanks for the report. As the author of this piece of mod_cfml, I will check the code, and try to reproduce the error.

As long as there's enough there to narrow it down, ace !
 

Like Jordan asked, what flavor of Linux are you using?

It's Amazon Linux, latest.
 

Also, do you know what the http request looked like? Eg. GET/POST, exact url (hostname can be omitted if you want), incoming headers... Was there any rewriting done already on the request?

Sorry, no, there's nothing that looks the same in access or error logs before each seg fault is recorded.

I would recommend compiling directly for sure.

I will look at doing that today and report back.

Tom

[Tom Chiverton]

Even with a freshly compiled module, we still get segfaults.
The Apache error log says

*** Error in `/usr/sbin/httpd': free(): invalid next size (fast): 0x00005634f5864920 ***
[Tue Oct 20 10:06:21 2015] [notice] child pid 6688 exit signal Segmentation fault (11), possible coredump in /tmp/apache-coredumps
*** Error in `/usr/sbin/httpd': free(): invalid next size (fast): 0x00005634f5864b50 ***
======= Backtrace: =========
/lib64/libc.so.6(+0x7d22d)[0x7f300acdf22d]
/etc/httpd/modules/mod_cfml.so(+0x18a8)[0x7f3000a768a8]
/usr/sbin/httpd(ap_run_handler+0x40)[0x5634f31c91d0]
/usr/sbin/httpd(ap_invoke_handler+0x69)[0x5634f31c9599]
/usr/sbin/httpd(ap_process_request+0x170)[0x5634f31d66d0]
/usr/sbin/httpd(+0x365f8)[0x5634f31d35f8]
/usr/sbin/httpd(ap_run_process_connection+0x40)[0x5634f31cf860]
/usr/sbin/httpd(+0x3de6b)[0x5634f31dae6b]
/usr/sbin/httpd(+0x3e2e2)[0x5634f31db2e2]
/usr/sbin/httpd(ap_mpm_run+0x9bf)[0x5634f31dc23f]
/usr/sbin/httpd(main+0xc7e)[0x5634f31b461e]
/lib64/libc.so.6(__libc_start_main+0xf5)[0x7f300ac83af5]
/usr/sbin/httpd(+0x176b9)[0x5634f31b46b9]

The gdb trace says in part

#10 0x00007f300ad93472 in dlerror_run (args=0x7ffc663de3a0, operate=0x7f300ad93370 <do_dlopen>) at dl-libc.c:46
#11 __GI___libc_dlopen_mode (name=name@entry=0x7f300addd8a6 "libgcc_s.so.1", mode=mode@entry=-2147483647) at dl-libc.c:163
#12 0x00007f300ad6ca25 in init () at ../sysdeps/x86_64/backtrace.c:52
#13 0x00007f300b234be0 in pthread_once () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_once.S:103
#14 0x00007f300ad6cb3c in __GI___backtrace (array=array@entry=0x7ffc663de660, size=size@entry=64) at ../sysdeps/x86_64/backtrace.c:103
#15 0x00007f300acd7e34 in __libc_message (do_abort=do_abort@entry=2, fmt=fmt@entry=0x7f300ade1328 "*** Error in `%s': %s: 0x%s ***\n")
    at ../sysdeps/unix/sysv/linux/libc_fatal.c:176

#16 0x00007f300acdf22d in malloc_printerr (ptr=<optimized out>, str=0x7f300ade1450 "free(): invalid next size (fast)", action=3) at malloc.c:4976
#17 _int_free (av=0x7f300b01d760 <main_arena>, p=<optimized out>, have_lock=0) at malloc.c:3804

#18 0x00007f3000a768a8 in modcfml_handler (r=0x5634f55f30f0) at mod_cfml.c:418
#19 0x00005634f31c91d0 in ap_run_handler (r=0x5634f55f30f0) at /usr/src/debug/httpd-2.2.31/server/config.c:157
#20 0x00005634f31c9599 in ap_invoke_handler (r=r@entry=0x5634f55f30f0) at /usr/src/debug/httpd-2.2.31/server/config.c:376
#21 0x00005634f31d66d0 in ap_process_request (r=r@entry=0x5634f55f30f0) at /usr/src/debug/httpd-2.2.31/modules/http/http_request.c:294
#22 0x00005634f31d35f8 in ap_process_http_connection (c=0x5634f55e1250) at /usr/src/debug/httpd-2.2.31/modules/http/http_core.c:190

Looking at the source, I see it's a free() of the struct created from config.CFMLHandlers. Very odd, that's static data ?

Our whole mod_cfml config is

LoadModule modcfml_module modules/mod_cfml.so
CFMLHandlers ".cfm .cfc .cfml"
ModCFML_SharedKey "some key here"

And then we include mod_rewrite rules in each virtual host we want to enable for Lucee that just do "RewriteRule ^/(.+\.cf[cm])(/.*)?$ http://127.0.0.1:8888/$1$2 [P,QSA]"

If I can be any further help tracing things down, drop me a line. Happy to send full stacks, the .so etc. off list if it'll help make mod_cfml more robust.

Tom

[Paul Klinkenberg]

Hi Tom,

Thanks for checking that.

There is help on the way, with a new version of mod_cfml. I will have to test it first, but it looks good, and will fix that malloc/free problem.

Kind regards,

Paul Klinkenberg

[Tom Chiverton]

On Tuesday, October 20, 2015 at 1:48:50 PM UTC+1, Paul Klinkenberg wrote:

There is help on the way, with a new version of mod_cfml. I will have to test it first, but it looks good, and will fix that malloc/free problem.

Awesome !

Great timing.

Tom

[Paul Klinkenberg]

Well, timing wasn't there. I looked at the code again because of your report, and noticed I could have used the Apache apr library much more, which does it's own memory management.
I still need to do test runs on Windows, Ubuntu, and centOS, but it works on my mac already.

Would you have a test server on AWS where you can test it on afterwards?

Kind regards,

Paul Klinkenberg

------------

--

[Tom Chiverton]

On Tuesday, October 20, 2015 at 9:17:01 PM UTC+1, Paul Klinkenberg wrote:

Would you have a test server on AWS where you can test it on afterwards?

Yes, I can clone our production system and check it compiles any time, and verify it basically works.

As we don't know what triggers it though, the only way to be sure is stick it on production and watch carefully :-)

Tom

[Paul Klinkenberg]

Hi Tom,

The main suspect would be this line: https://github.com/paulklinkenberg/mod_cfml/blob/master/C/mod_cfml.c#L418

Which is where a chunk of memory is freed, but somehow it doesn't work. It could be because the memory wasn't allocated in the first place, but I would then have expected an error a few lines earlier.

The only two other free() actions are done on line 456 and 458, but those are checked (if not null).

I am now using the APR memory pool, which frees all memory after the request is done. That should be a lot safer.

I did the tests on Windows and centOS already, only have to do Ubuntu now.

Kind regards,

Paul Klinkenberg

[Jordan Michaels]

I'd like to point out that Paul is doing this for free, in his own time, as a committed member of the community. No one is paying him, or giving him compensation in any way for the time he gives. This is what 'community' means.

Thanks Paul, for volunteering and donating your obvious talent for the good of others. You are an inspiration for us all.

-Jordan

----- Original Message -----
From: "Paul Klinkenberg" <pa...@ongevraagdadvies.nl>
To: "mod cfml" <mod_...@googlegroups.com>
Sent: Wednesday, October 21, 2015 4:57:26 AM
Subject: Re: [mod_cfml] Segfaults on Linux

Hi Tom,

The main suspect would be this line: https://github.com/paulklinkenberg/mod_cfml/blob/master/C/mod_cfml.c#L418 <https://github.com/paulklinkenberg/mod_cfml/blob/master/C/mod_cfml.c#L418>

To unsubscribe from this group and stop receiving emails from it, send an email to mod_cfml+u...@googlegroups.com <mailto:mod_cfml+u...@googlegroups.com>.
For more options, visit https://groups.google.com/d/optout <https://groups.google.com/d/optout>.

[Paul Klinkenberg]

Hey Jordan,

Thanks for the kind words :) We all know you do the exact same thing for the community, so thank you too!

Kind regards, Paul

[Paul Klinkenberg]

Hi Tom,

If you can find some time, could you please compile mod_cfml with this version: https://github.com/paulklinkenberg/mod_cfml/tree/apache-module-v1.1.06/C

Be sure to back up your current mod_cfml.so!

Thanks, kind regards,

Paul Klinkenberg

[Tom Chiverton]

After swapping in the new .so, I get errors after doing 'apache restart':

[Thu Oct 22 08:22:05 2015] [notice] child pid 1047 exit signal Illegal instruction (4)

If I try again, though, it starts up OK and seems to work OK.

It's mid-morning here, and so I wont be able to try it in production for several hours. I'll do some more tests on our dev system too.

Tom

[Paul Klinkenberg]

Hi Tom,

There is a difference between apachectl's restart vs. start+stop:

Sending the HUP or restart signal to the parent causes it to kill off its children like in TERM, but the parent doesn't exit. It re-reads its configuration files, and re-opens any log files. Then it spawns a new set of children and continues serving hits.

That's probably why you rcvd the error.

Kind regards,

Paul Klinkenberg

------------

[Paul Klinkenberg]

Hi Tom,

I know it is weekend, but did you already test the updated version? If it works, fingers crossed, I will do a new release soon.

Kind regards,

Paul Klinkenberg

[Tom Chiverton]

I swapped it in a few hours ago to our production servers.

It seems to be working OK (though a simple stop and start via apachectl didn't seem to work, I had to re-start it again. Probably the same thing as before where all the children have to be killed off.).

I'll check the error log later today.

Tom

[Tom Chiverton]

Oh, there is a compile error on one of our older machines :

mod_cfml.c:1: error: stray '\357' in program
mod_cfml.c:1: error: stray '\273' in program
mod_cfml.c:1: error: stray '\277' in program

Retyping the first line (the suggested fix for unicode characters in C source) did't change the error.

Any ideas ?

Tom

[Tom Chiverton]

On Monday, October 26, 2015 at 9:27:15 AM UTC, Tom Chiverton wrote:

Oh, there is a compile error on one of our older machines :

mod_cfml.c:1: error: stray '\357' in program

It looks like a UTF8 BOM (which shouldn't be there ?).

If I remove it
# xxd -g 1 -s 3 mod_cfml.c | xxd -g 1 -s -3 -r
then the diff with the original lists
<U+FEFF>
at the start
 
Tom

[Tom Chiverton]

Also, I was just looking through the logs, and it looks like it still logs the old version :

[mod_cfml] Starting mod_cfml version: 1.1.05
Oct 26, 2015 9:47:14 AM org.apache.catalina.startup.HostConfig deployDirectory

Tom

[Paul Klinkenberg]

Hi Tom,

Luckily you pasted 2 lines of log data: the second line indicates you are viewing the Tomcat logs. Nothing changed there, it is a seperate component which is still on the old version.

You can safey ignore it :)

Paul

[Tom Chiverton]

Oh, good spot. It's obviously working well with the older Valve then. Unexpected test ;-)

Tom

[Tom Chiverton]

No seg faults logged today. As we used to get them a few times an hour, I think we can call it fixed.

Thanks for the quick turn around of totally rewriting the memory allocation !

Tom

[Paul Klinkenberg]

Hi Tom,

That's good news. I will create a new release soonish. 

Thanks for the feedback and testing!

Kind regards,

Paul

[Paul Klinkenberg]

Hi Tom,

Does it compile and work after you removed the BOM? It indeed shouldn't be there, I'll have to check that later.

Kind regards,

Paul Klinkenberg

[Paul Klinkenberg]

Oow, that's weird; the previous mail should have been sent 2 days ago ;-/ Please ignore it.

Paul

[Tom Chiverton]

I'd just like to resurrect this thread.

We're having a similar issue with the latest mod_cfml connector on a 64bit Ubuntu Server LTS. Recompiling from source did not help. What *did* was using the alternative branch, https://github.com/paulklinkenberg/mod_cfml/tree/apache-module-v1.1.06/C mentioned a few years ago.

Odd ? Has maybe not all of the branch been moved to trunk ?