Server občas ukončí request chybou Fatal error: Maximum execution time
- TomasHalasz
- Bronze Partner | 79
Ahoj,
už si nevím rady s jednou zajímavou a nepříjemnou chybou. Vytvořil jsem si chatovací komponentu, kde na straně klienta každých 25 sec. volám ajaxově handle, který mi vrací změny v chatu. Všechno funguje zdánlivě bez problémů. Ve firebugu vidím každých 25 sec. volání s úspěšnou odezvou ve formě snippetů. Odpovědi od admina se tedy zobrazují, stejně tak naopak zprávy od uživatele se zobrazují adminovi. Jenže jsem zjistil, že občas zůstane v logu toto:
[2014-06-26 06-47-30] Fatal error: Maximum execution time of 60 seconds exceeded in /mnt/data/accounts/s/web/data/www/mojedomena.com/vendor/nette/caching/src/Caching/Storages/FileStorage.php:270 @ http://mojedomena.com/ru/?do=chat-chatAnswer @@ exception-2014-06-24-15-08-28-13168c7a15baabb5577a47b6df315d87.html
když se podívám na tracy log tak tam je chyba:
File: .../vendor/nette/caching/src/Caching/Storages/FileStorage.php:270
267: // cleaning using file iterator
268: if ($all || $collector) {
269: $now = time();
270: foreach (Nette\Utils\Finder::find('_*')->from($this->dir)->childFirst() as $entry) {
271: $path = (string) $entry;
272: if ($entry->isDir()) { // collector: remove empty dirs
273: @rmdir($path); // @ - removing dirs is not necessary
274: continue;
těch exception je v logu třeba deset za hodinu a někdy jsou na stejném místě a někdy na jiných např.
[2014-06-26 06-31-37] Fatal error: Maximum execution time of 60 seconds exceeded in /mnt/data/accounts/s/web/data/www/mojedomena.com/vendor/nette/finder/src/Finder/Finder.php:105 @ http://mojedomena.com/ru/games/?do=chat-chatAnswer @@ exception-2014-06-24-14-45-52-a0360729f0c42a1912180251ab3c39a8.html
File: .../vendor/nette/finder/src/Finder/Finder.php:105
98: private function select($masks, $type)
99: {
100: $this->cursor = & $this->groups[];
101: $pattern = self::buildPattern($masks);
102: if ($type || $pattern) {
103: $this->filter(function($file) use ($type, $pattern) {
104: return !$file->isDot()
105: && (!$type || $file->$type())
106: && (!$pattern || preg_match($pattern, '/' . strtr($file->getSubPathName(), '\\', '/')));
107: });
108: }
Nette je poslední verze 2.2.2, ale dělalo to i s verzí 2.1 a 2.2.1 .
V tom handle chatAnswer dělám jen to, že se připojuju k MySQL, zjistím nové odpovědi a zapíšu k uživateli aktuální datetime abych měl příznak, že je uživatel online.
Jak jsem psal na začátku, všechno funguje v pořádku jen občas dostanu ten zápis exception do logu. Ve firebugu přitom žádný error u ajax requestů není. Už si fakt nevím rady. Netušíte někdo čím by to mohlo být nebo kde hledat chybu?
Ten handle chatAnswer končím jen $this->redrawcontrol(‚nazevsnippetu‘); nemůže být v tom chyba? Nemělo by se to ukončit ještě nějak jinak ?
Tady je ještě ten handle:
public function handleChatAnswer()
{
if ($this->parent->presenter->isAjax())
{
try {
$this->section = $this->parent->session->getSection('t2q');
if (!is_null($this->section->chat_id))
{
//save datetime of last_response in chat
$this->presenter->chatManager->lastResponse($this->section->chat_id);
//on LP we must show chat if there is change from status 0 to 1
if ($row = $this->presenter->chatManager->getOneChat($this->section->chat_id)->fetch())
{
if ($row->status == 1 && $this->section->chat_status == 0)
{
$this->section->chat_status = 1;
$this->section->ChatShow = TRUE;
$this->section->ChatHideTime = NULL;
$this->redrawControl('snptform');
$this->redrawControl('chatshow');
}
if ($row->status == 2 && $this->section->chat_status == 1)
{
//chat was closed by admin
$this->section->chat_id = NULL;
$this->section->answersCount = 0;
$this->section->ChatShow = FALSE;
$this->redrawControl('snptmess');
$this->redrawControl('snptform');
$this->redrawControl('snpttitle');
}
}
//save last_response for current user 20.06.2014 and also chat_id 25.6
$this->presenter->userManager->setResponse($this->presenter->user->getId(),$this->section->chat_id);
$this->presenter->userManager->setLocation($this->section->activeLocation, $this->presenter->user->getId());
}
else
{
//there is not open chat yet so we must look if admin have opened some one for this user
//check if there is another chat opened by admin
if ($this->presenter->user->isLoggedIn())
{
//if is user logged in, we get lastuserchat by his Id
if ($row = $this->presenter->chatManager->getLastUserChat($this->presenter->user->getId())->fetch())
{
$this->section->chat_id = $row->id;
$this->presenter->chatManager->lastResponse($this->section->chat_id);
$this->section->ChatShow = TRUE;
$this->section->ChatHideTime = NULL;
$this->redrawControl('snptform');
$this->redrawControl('chatshow');
}
//save last_response for current user 20.06.2014 and also chat_id 25.6.
$this->presenter->userManager->setResponse($this->presenter->user->getId(),$this->section->chat_id);
$this->presenter->userManager->setLocation($this->section->activeLocation, $this->presenter->user->getId());
}else{
//if user is not logged in and there is no section->chat_id, we must made new chat
if ($row = $this->presenter->chatManager->newGuestChat($this->presenter->locale, $this->getIp()))
{
//we must only prepare chat to action by admin or user
$this->section->chat_id = $row->id;
$this->section->chat_status = 0;
$this->redrawControl('snptform');
}
}
}
$this->redrawControl('snpttitle');
$this->redrawControl('snptmess');
$row = NULL;
} catch (Nette\Security\AuthenticationException $e) {
$this->section = $this->parent->session->getSection('t2q');
$this->section->message_title = 'messages.signin.signin';
$this->section->message_text = $e->getMessage();
$this->section->show_message = true;
}
}else{ //not ajax request
$this->presenter->terminate();
}
}
Díky moc za každou radu.
- mirimCZ
- Člen | 24
První rada: poučka co mám od Jirky Knesla – „Kód by se měl komentovat sám. Pokud píšete Co se děje, něco děláte špatně, komentář by měl říkat Proč se to děje.“ V tvém případě ta metoda vysloveně žebrá o dekomponování do více metod, navádí k tomu i pětinásobné zanoření bloků… Pokud by jsi chtěl o této problematice víc informací, doporučil bych knížku Čistý Kód (napsal Robert C. Martin).
Co se týče chyby – hodil by si sem celý report z tracy? Je divné, že to padá v různých místech. Chybu by „vyřešilo“ navýšení max execution time přes set_time_limit() přímo v té metodě. :) Jinak potřebuješ lokalizovat ten kód, který ti tak dlouho trvá. Googli php benchmark, žádné hotové řešení na to bohužel neznám, onehdá když sem si měřil běh, byl to jen takovej „one time bastl“. Debbuger na to má metodu Debugger::timer(), tenkrát mi nevím proč nevyhovovala, ale tobě by to snad mohlo stačit :)
Ještě se zkus podívat kolik máš v cestě FileStorage->dir souborů, nevím nad jakým adresářem máš ten filestorage vytvořený, nedokážu si představit číslo kolik by jich tam muselo být, aby to na tom failovalo.
Editoval mirimCZ (26. 6. 2014 13:16)
- TomasHalasz
- Bronze Partner | 79
mirimCZ napsal(a):
.....Jinak potřebuješ lokalizovat ten kód, který ti tak dlouho trvá. Googli php benchmark, žádné hotové řešení na to bohužel neznám, onehdá když sem si měřil běh, byl to jen takovej „one time bastl“. Debbuger na to má metodu Debugger::timer(), tenkrát mi nevím proč nevyhovovala, ale tobě by to snad mohlo stačit :)
To zní jako dobrý nápad :-) Zkusím co z toho vypadne
mirimCZ napsal(a):
Ještě se zkus podívat kolik máš v cestě FileStorage->dir souborů, nevím nad jakým adresářem máš ten filestorage vytvořený, nedokážu si představit číslo kolik by jich tam muselo být, aby to na tom failovalo.
Nevím přesně jak to zjistit. Jestli to jsou složky v temp adresáři tak
tam je toto:
_Nette.Database.f1b029d4a0909c9c057295a798a647ba souborů: 219341 celkem:
26M
_Nette.Database.a05c180e431e271f763ce40891df59bb souborů: 1 :-)
Je těch 219tis. souborů hodně? A proč jich tam je tolik? Ten web má návštěvnost tak 500 lidí za den…
- TomasHalasz
- Bronze Partner | 79
Zatím to vypadá, že příčinou bylo těch 219tis. souborů v cache. Vymazal jsem je a chyby se přestaly objevovat.
Co je horším nette je usilovně zase vytváří. Za poslední půl hodinu mám v cache nových 771 souborů všechny s velikostí 117 bajtů a téměř identickým obsahem:
<?php //netteCache[01]000070a:2:{s:4:"time";s:21:"0.46683900 1403791571";s:10:"serialized";b:1;}?>a:1:{s:2:"id";b:1;}
liší se pouze v tomto:
s:21:"0.46683900 1403791571"
Dá se nějak vypnout cache jen pro konkrétní část kódu ?
- TomasHalasz
- Bronze Partner | 79
matej21 napsal(a):
ukaz, jak sestavujes dotazy..
Je to control takže v třídě mám metodu handleChatAnswer a v ní:
$this->presenter->chatManager->lastResponse($this->section->chat_id);
v modelu pak:
/**
* Save last response datetime to chat
* @param type $id
*/
public function lastResponse($id)
{
$now = new \Nette\DateTime;
return ($this->database->table(self::TABLE_NAME_CHAT)->where(array(self::COLUMN_CHAT_ID => $id))->update(array(self::COLUMN_CHAT_LAST_RESPONSE => $now)));
}
pak mám v té metodě handleChatAnswer také:
if ($row = $this->presenter->chatManager->getOneChat($this->section->chat_id)->fetch())
a v modelu:
/**
* Return chat by its id
* @param type $id
* @return type
*/
public function getOneChat($id)
{
return $this->database->table(self::TABLE_NAME_CHAT)->where(self::COLUMN_CHAT_ID. '= ?',$id );
}
Mám tam něco špatně? Ten $this->presenter vadí ?
- David Matějka
- Moderator | 6445
V tomhle nevidim nic, co by to zpusobovalo. Bylo by dobre zjistit, ktery
dotaz presne to zpusobuje.
Nette\Database totiz tuhle cache vytvari pro kazdy „jiny“ dotaz. Tedy
pro dotazy
$this->database->table('article')->where('id = ?', 1);
a
$this->database->table('article')->where('id = ?', 1)->where('published IS NOT NULL');
vytvori zaznam v cache pro kazdy jednou (nejsou dulezite hodnoty parametru)
Takze se koukni, jestli tam nemas nejaky hodne dynamicky dotazy, kde se dle
nejakeho filtru pridavaji ruzny kombinace where apod. Nebo jestli tam nemas
chybu, ze dotaz misto spravneho ->where('id = ?', $id)
pouzivas
bez parametru ->where('id = $id')
EDIT: pokud najdes dotaz, ktery to zpusobuje, tak rucni specifikaci
->select('sloupecek1, ...')
vypnes tuhle cache, pripadne muzes
zkusit tenhle hack
Editoval matej21 (26. 6. 2014 16:32)
- TomasHalasz
- Bronze Partner | 79
Aha, vyloženě dynamického dotazu si nejsem vědom :-)
Našel jsem jen tohle:
public function getLastUserChat($users_id)
{
return $this->database->table(self::TABLE_NAME_CHAT)->where(self::COLUMN_CHAT_USERS_ID. '= ? AND '. self::COLUMN_CHAT_STATUS . ' IN (0,1,3)',$users_id )->order(self::COLUMN_CHAT_ID.' DESC');
}
konkrétně toto: self::COLUMN_CHAT_STATUS . ' IN (0,1,3)'
Dynamického na tom není nic :-) ale nevadí mu to když to není parametrem?
Editoval TomasHalasz (26. 6. 2014 16:52)
- David Matějka
- Moderator | 6445
imho by nemelo, ale radeji pouzij:
return $this->database->table(self::TABLE_NAME_CHAT)->where(self::COLUMN_CHAT_USERS_ID. '= ? AND '. self::COLUMN_CHAT_STATUS . ' IN ?',$users_id, array(0, 1, 3) )->order(self::COLUMN_CHAT_ID.' DESC');
(nebo to pro lepsi citelnost rozdel do dvou where, stejne se totiz spojuji pomoci AND
- TomasHalasz
- Bronze Partner | 79
matej21 napsal(a):
.....
Takze se koukni, jestli tam nemas nejaky hodne dynamicky dotazy, kde se dle nejakeho filtru pridavaji ruzny kombinace where apod. Nebo jestli tam nemas chybu, ze dotaz misto spravneho->where('id = ?', $id)
pouzivas bez parametru->where('id = $id')
Tak to bylo ono. Až teď večer mi došlo, že v tom handle invaliduju snippety a ty si taky berou nové hodnoty z databáze. No a ty selecty, které plnily snippety jsem měl úplně špatně… skoro přesně to co jsi psal:
return $this->database->table(self::TABLE_NAME_MESS)
->where(self::COLUMN_MESS_CHAT_ID.'='.$id.' AND '.self::COLUMN_MESS_CREATED.'>="'.$ChatHideTime.'" AND '.self::COLUMN_MESS_TYPE.'=1')
->count(self::COLUMN_MESS_ID);
stačilo to dát takto:
return $this->database->table(self::TABLE_NAME_MESS)
->where(self::COLUMN_MESS_CHAT_ID.'= ? AND '.self::COLUMN_MESS_CREATED.'>= ? AND '.self::COLUMN_MESS_TYPE.' = ?', $id, $ChatHideTime, 1)
->count(self::COLUMN_MESS_ID);
a je po problému :-)
díky moc!