News:

Want to get involved in developing SMF, then why not lend a hand on our github!

Main Menu

error message that says mysql_real_escape_string() expects parameter 2....

Started by Quexinos, February 23, 2011, 12:03:19 AM

Previous topic - Next topic

Arantor

How else can you explain it? A deconstruction has been posted evidencing that sometime between the start of a SMF script execution and the end of it, the database connection was compromised. The example you showed me fits the exact same pattern.

I say again, until someone can show me evidence to the contrary, demonstrating some circumstances for a PHP or SMF bug I can only conclude it is an event elsewhere on the server caused MySQL to drop connections.
Holder of controversial views, all of which my own.


charlottezweb

I can't explain it, I'm not the expert.   :)

Just seems odd it started being reported by numerous users here since the latest releases and I've not seen it on servers that I've had running SMF sites for years and years. 


Quexinos

Quote from: Arantor on February 25, 2011, 05:00:49 PM
How else can you explain it? A deconstruction has been posted evidencing that sometime between the start of a SMF script execution and the end of it, the database connection was compromised. The example you showed me fits the exact same pattern.

I say again, until someone can show me evidence to the contrary, demonstrating some circumstances for a PHP or SMF bug I can only conclude it is an event elsewhere on the server caused MySQL to drop connections.
I have a question just really quick, I'm looking at my error log and that error that I said happens several times... hasn't happened in like two days.  I posted that yesterday.... you don't think what happened yesterday was a different error do you?  Just want to make sure is all. 

Arantor

I honestly don't know. It might be the same error, it might be a different error, may have different causes but present the same symptoms.

I think, though, it was just a bad confluence of events, and mostly likely triggered by something else on the server that's insecure and just coincided with the SMF patch.
Holder of controversial views, all of which my own.


charlottezweb

I was thinking from another direction.  If a "traffic spike" is the cause, then wouldn't something in the code (maybe a mod?) that causes SMF to loop itself exponentially be the same thing as a traffic spike?  That would ultimately have the same result right?   

I'm just thinking about that one IP with 22,000 error log entries in under a minute.   I'd consider that a traffic spike for sure although it appears to be the result of a misconfiguration somewhere.  Mysql or SMF, I can't say.

Arantor

Assuming the backtrace posted here is the same error, and it presents all the same symptoms, there is no looping back on itself. The trace shows you every function in the chain, as each function calls another, it's another on the stack. The stack was 14 long, and I explained every step of the stack, and none of them indicate loops.

As that stack clearly said, and I can't stress how bluntly it put it: at some point during execution it tried to query for information, and MySQL itself returned the error message that the connection was lost. That's it. Everything that happened after, happened as a direct consequence of the connection being dropped, a state which should never happen and cannot be defended against without significantly increasing SMF's load.

The only explanation I can find that explains all the behaviour presented is a load spike, that either directed at MySQL or through another app on the same server which triggered high load on MySQL, causing it to drop connections.


What we need is to start logging instances of this, perhaps with a variation of the code I posted (the final version!) and collect more stack traces, but without that, we can't be sure of anything. All I can say is right now the evidence I have is not consistent with an SMF bug.
Holder of controversial views, all of which my own.


larryhyman

If you use Google to search this error, you will find that it is all over the place... people say it's from php4 or mysql4, but when people use version 5 of php and mysql and still get the error, they say it's because the script is using multiple connections to the database (makes me wounder if they are using persistent connections when persistent connections are not supported on their server. Also some people say that this only happens when to many people are on their site causing to many connections to the mysql server... what ever the case it does appear to be an issue wit some shared mysql servers (maybe not enough connections allowed in the server setup). I don't know, some people have this problem while others do not, the only difference is they are on a different web account (leading back to thinking it is the providers mysql configuration that is at fault...)

The only thing that I found that comes even close to a solution is that somebody was saying that the mysql server had to be rebooted and then the problem went away (reboot the mysql server? did they change the configuration?)

anyways I wish you the best of luck (including all the 1000's of other people that have this error) as I have never heard of this before...

Please let me know if you can get your provider to increase the amount of concurrent mysql connections and let me know if that solves the problem...
In god we trust, all others pay cash !

http://hyman.sytes.net

Arantor

QuoteAlso some people say that this only happens when to many people are on their site causing to many connections to the mysql server... what ever the case it does appear to be an issue wit some shared mysql servers (maybe not enough connections allowed in the server setup).

Exactly as I've said in this thread, then... ;)
Holder of controversial views, all of which my own.


Spuds

I've also been getting this error and always assumed that it was caused by a server or other website  on the server causing mysql to drop connections.  It was one of those things that started 'one day' on a forum that I had not made changes on.  RC4 or RC5. 

This is a larger file 980+ array elements so an example of one of those times that a lot of errors were created in a short time.  Don't know if this will provide any more information of just more of the same, but here it is.


Arantor

Interesting log, that. I haven't been over it with a fine tooth comb, will do that tonight, but that does suggest something is awry with Subs-Db-Mysql.php. Do you have any mods that modified that file?

The biggest problem with that log is that the actual error returned by smf_db_error is not available, so at entry 985 something went sour with that query and it's not clear why.
Holder of controversial views, all of which my own.


Spuds

Several mods but none that changed Subs-Db-Mysql.php.  Just ran a diff on this file from my site and from the rc5 package and the only delta is the block of debug code. 

I had noticed the first database error in the trace but could not figure out what occurred.  I even tried taking the query and using it via phpMyAdmin and it ran fine (hoping something maybe went bad with the serialize). 

Arantor

I just had an idea, similar to what I've already stated but it would explain everything, including the rampant errors in their entirety, as that was something I couldn't entirely explain before.

OK, what do we know for sure? Well, at some point, the connection is failing, we know that, we accept that fact - the evidence validates that very fact, that the connection is dropped sometime after page generation starts, but sometime before it ends.

In the first case where I had logs, the connection dropped, errors leaked out but they weren't insane levels of error, it wasn't nested, it just died softly as far as the log said. Spuds' log shows a different story, but interestingly it starts exactly the same way: a connection is being dropped. We don't have the full details of error but it's a fair bet to say that it's failing for the same reason - something external causes it to drop. The difference is in what happens next.

In the first log, the error is dumped, execution proceeds but terminates fairly rapidly, not entirely sure why because it's falling back through execution rather than hitting a roadblock, as it does in Spuds' case.

Consider this: there's a error due to the failed connection, which causes something to need to be logged in the DB... but the connection's down so we see a failure in the replace callback, which would cause an error to need to be logged in the DB... but the connection's down so we get another failure in the replace callback... repeat until either the stack exhausts, or PHP terminates, typically the former.

On my sites this hasn't happened, all the sites are on a single VPS and I'm the only one with access to it, and I have total control over what goes on. In consequence I haven't had the problem because I have more fine grained control over what's on it - it's not a shared host, and load's low the whole time anyway.

But all the sites affected are on shared hosts, so it's entirely possible that something is occurring on the shared hosts that's causing problems, the fallout being the issues we've seen. Remember, SMF isn't the only one having been hit with the bots, it's not just SMF sites being targetted, phpBB and MyBB have been too (at least), and I think the timing is just unfortunate.

As an initial mitigating factor, turning off error logging should prevent the massive error strikes, but a stronger method does need to be devised. I got a few ideas, will try them out shortly.


IOW, I saw no evidence before to suggest an SMF bug. I'm still not classing this as a bug, per se, because it's not in my mind. It is something to be resolved, however. A PHP/MySQL connection dropping unexpectedly is an edge condition, and the fallout can be pretty catastrophic as we've seen. There is still no evidence to point the blame directly at SMF, other than that it should handle DB failures like this a little more gracefully than it currently does.
Holder of controversial views, all of which my own.


Spuds

First off, a sincere thank you for taking the time to look in to this.

QuoteConsider this: there's a error due to the failed connection, which causes something to need to be logged in the DB... but the connection's down so we see a failure in the replace callback, which would cause an error to need to be logged in the DB... but the connection's down so we get another failure in the replace callback... repeat until either the stack exhausts, or PHP terminates, typically the former.
That makes sense and does explain how it could on occasion pump out a hideous number of error log entries in a very short time. 

I've captured a couple of the short logs, the 14 index style, but generally they are along the lines of what I posted with 700-1000 entries.  Seems to happen a couple of times a day, I'm collecting that data to provide back to the host to see if it correlates to something/anything. 

The log times often show the event lasting just a few seconds, I don't think I've seen one lasting more than say 10-15 seconds and most often 1 or 2 seconds. 

QuoteAs an initial mitigating factor, turning off error logging should prevent the massive error strikes, but a stronger method does need to be devised. I got a few ideas, will try them out shortly.
Done, and when you need a test bed for any changes just let me know.

Arantor

OK, I think I hit a fix, at least it seems to be safe in the testing I've done.

Remove the debug code if you had it, and put this code after list ($values, $connection) = $db_callback;

if (!is_resource($connection))
    db_fatal_error();


This will push it out of regular execution and into a place where an error message should be emitted to the user, and execution will safely exit without any queries back to the database to log anything, which is where this all failed.

I'm still wondering if that function also needs to ensure output buffers are cleaned and closed before outputting, just in case some output occurred first or not.

If that IS needed, which I'm not 100% sure on, the code would be as follows in Errors.php:
Code (find) Select
function show_db_error($loadavg = false)
{
global $sourcedir, $mbname, $maintenance, $mtitle, $mmessage, $modSettings;
global $db_connection, $webmaster_email, $db_last_error, $db_error_send, $smcFunc;


Code (after that, add) Select
// Just check we're not in any buffers, just in case.
for ($i = ob_get_level(); $i > 0; $i--)
@ob_end_clean();


In case anyone's wondering for the @, there are circumstances where ob_get_level will return 1 more output buffer than it should, so we're going to clean down all of them regardless.

EDIT: Tweaked that loop slightly, just in case of real oddities.
Holder of controversial views, all of which my own.


Spuds

Thanks, I've put those changes in place.  Now just to work with the host to figure out what is causing mySQL to drop the connection in the first place, but till then if this prevents generating those long error files and keeps smf from beating on a dead connection I'll be happy.

Arantor

Holder of controversial views, all of which my own.


Quexinos

That's Arantor, that'll be very helpful, I was about to ask if this was possible ^_^

nicor2k

Hi everybody!

I get this huge list of error-msgs when trying to include SSI.php inside a WordPress theme. Thanks to Arantor at least the errors are gone with this code:

   if (!is_resource($connection)) { die(); }

Is this a good way to use it, or do you suggest something else?


Quote from: Arantor on February 26, 2011, 06:41:46 PM
OK, I think I hit a fix, at least it seems to be safe in the testing I've done.

Remove the debug code if you had it, and put this code after list ($values, $connection) = $db_callback;

if (!is_resource($connection))
    db_fatal_error();


This will push it out of regular execution and into a place where an error message should be emitted to the user, and execution will safely exit without any queries back to the database to log anything, which is where this all failed.

I'm still wondering if that function also needs to ensure output buffers are cleaned and closed before outputting, just in case some output occurred first or not.

If that IS needed, which I'm not 100% sure on, the code would be as follows in Errors.php:
Code (find) Select
function show_db_error($loadavg = false)
{
global $sourcedir, $mbname, $maintenance, $mtitle, $mmessage, $modSettings;
global $db_connection, $webmaster_email, $db_last_error, $db_error_send, $smcFunc;


Code (after that, add) Select
// Just check we're not in any buffers, just in case.
for ($i = ob_get_level(); $i > 0; $i--)
@ob_end_clean();


In case anyone's wondering for the @, there are circumstances where ob_get_level will return 1 more output buffer than it should, so we're going to clean down all of them regardless.

EDIT: Tweaked that loop slightly, just in case of real oddities.

Arantor

I would suggest you use the code I posted, not the code you've used.
Holder of controversial views, all of which my own.


nicor2k

Yes, I understand that - but its nearly the same, isn't it? I just don't need/want a db_fatal_error output: When including the SSI in a wordpress theme, the error comes everytime...

Advertisement: