Start a new topic

Server getting crushed

plee@virtualpremise.com @ Tue Apr 01 09:35:47 EEST 2014
This morning, (no April Fools please!), our server started cranking out 25 MB log files every 5 minutes filled with messages such as:

04/01/2014 10:20:58 AM|SQL:Got:{sort_order=1334, userid=1, key=(rename):Rename, for_context_menu=true, for_menu=true, value=javascript:performAction('rename');}
04/01/2014 10:20:58 AM|SQL:Got:{sort_order=1335, userid=1, key=(rename):Rename, for_context_menu=true, for_menu=true, value=javascript:performAction('rename');}
04/01/2014 10:20:58 AM|SQL:Got:{sort_order=1336, userid=1, key=(rename):Rename, for_context_menu=true, for_menu=true, value=javascript:performAction('rename');}

and

04/01/2014 10:20:58 AM|SQL:Got:{sort_order=4216, userid=1, key=(rename):Rename, for_context_menu=true, for_menu=true, value=javascript:performAction('rename');}
04/01/2014 10:20:58 AM|SQL:Got:{sort_order=4217, userid=1, key=(rename):Rename, for_context_menu=true, for_menu=true, value=javascript:performAction('rename');}
04/01/2014 10:20:58 AM|SQL:Got:{sort_order=4218, userid=1, key=(rename):Rename, for_context_menu=true, for_menu=true, value=javascript:performAction('rename');}
04/01/2014 10:20:58 AM|SQL:Got:{sort_order=4219, userid=1, key=(rename):Rename, for_context_menu=true, for_menu=true, value=javascript:performAction('rename');}
04/01/2014 10:20:58 AM|SQL:Got:{sort_order=4220, userid=1, key=(rename):Rename, for_context_menu=true, for_menu=true, value=javascript:performAction('rename');}
04/01/2014 10:20:58 AM|SQL:Got:{sort_order=4221, userid=1, key=(rename):Rename, for_context_menu=true, for_menu=true, value=javascript:performAction('rename');}
04/01/2014 10:20:58 AM|SQL:Got:{sort_order=4222, userid=1, key=(rename):Rename, for_context_menu=true, for_menu=true, value=javascript:performAction('rename');}
04/01/2014 10:20:58 AM|SQL:Got:{sort_order=4223, userid=1, key=(rename):Rename, for_context_menu=true, for_menu=true, value=javascript:performAction('rename');}
04/01/2014 10:20:58 AM|SQL:Got:{sort_order=4224, userid=1, key=(slideshow):QuickView, for_context_menu=true, for_menu=false, value=javascript:performAction('quickView');}
04/01/2014 10:20:58 AM|SQL:Got:{sort_order=4225, userid=1, key=(slideshow):QuickView, for_context_menu=true, for_menu=false, value=javascript:performAction('quickView');}
04/01/2014 10:20:58 AM|SQL:Got:{sort_order=4226, userid=1, key=(slideshow):QuickView, for_context_menu=true, for_menu=false, value=javascript:performAction('quickView');}
04/01/2014 10:20:58 AM|SQL:Got:{sort_order=4227, userid=1, key=(slideshow):QuickView, for_context_menu=true, for_menu=false, value=javascript:performAction('quickView');}
04/01/2014 10:20:58 AM|SQL:Got:{sort_order=4228, userid=1, key=(rename):Rename, for_context_menu=true, for_menu=true, value=javascript:performAction('rename');}
04/01/2014 10:20:58 AM|SQL:Got:{sort_order=4229, userid=1, key=(rename):Rename, for_context_menu=true, for_menu=true, value=javascript:performAction('rename');}
04/01/2014 10:20:58 AM|SQL:Got:{sort_order=4230, userid=1, key=(rename):Rename, for_context_menu=true, for_menu=true, value=javascript:performAction('rename');}
04/01/2014 10:20:58 AM|SQL:Got:{sort_order=4231, userid=1, key=(rename):Rename, for_context_menu=true, for_menu=true, value=javascript:performAction('rename');}
04/01/2014 10:20:58 AM|SQL:Got:{sort_order=4232, userid=1, key=(rename):Rename, for_context_menu=true, for_menu=true, value=javascript:performAction('rename');}
04/01/2014 10:20:58 AM|SQL:Got:{sort_order=4233, userid=1, key=(rename):Rename, for_context_menu=true, for_menu=true, value=javascript:performAction('rename');}
04/01/2014 10:20:58 AM|SQL:Got:{sort_order=4234, userid=1, key=(rename):Rename, for_context_menu=true, for_menu=true, value=javascript:performAction('rename');}
0

There are literally 160K lines of this stuff in the logs, and the server itself is not responding to basic FTP requests.

What is generating this log activity, does it indicate a failure, or can we safely turn off a logging setting to keep this stuff from taking the server down?

spinkb @ Tue Apr 01 09:40:17 EEST 2014
Its not a failure.

Your prefs, user config, debug flag is enabled, so its being verbose on its SQL queries.

And check your logging, debug level and make sure its only at level 1.

Thanks,
Ben
plee@virtualpremise.com @ Tue Apr 01 15:04:49 EEST 2014
Modifying the logging entries resolved the log files filling quickly, but has done nothing to resolve the server becoming unresponsive.

This instance has been in place for several months without exhibiting this kind of behavior. The web admin screen is unusable.

We are current on the latest v.6 Crush version, and the latest Java version.

Basically the java runtime sits pegged at 50% CPU usage, with frequent jumps to 100%

spinkb @ Tue Apr 01 15:11:59 EEST 2014
What exact CrushFTP version is this? (latest means nothing as we push builds daily)

How big is your sessions.obj file?

How big is your statsDB folder?

If your on the latest (currently 6.4.0_164 or 7.0.2_93), then there is a button on t eh about tab to dump a thread list. Provide that so I can see what the server is doing when its acting very slow.

Email it directly to support and not here.

Thanks,
Ben
plee@virtualpremise.com @ Tue Apr 01 17:41:40 EEST 2014
Looks like we identified the culprit of the problems.

Nothing to do with CrushFTP.

Found two sources of legitimate connections which were run-aways and generating huge connection traffic. Once we got these back to normal operations the performance issues on Crush went away. Definitely an unwelcome load test.

Will spend a bit of time this evening evaluating our connection limits settings to protect ourselves from future occurrences.

Thanks for the support.
Login to post a comment