creating severe load on system by logging thousands of unlink errors in DB log

yaoweizhen - September 26, 2009 - 18:24
Project:Cache Router
Version:6.x-1.0-rc1
Component:Miscellaneous
Category:bug report
Priority:critical
Assigned:Unassigned
Status:active
Description

warning: unlink(/tmp/cache_menu_lock) [function.unlink]: No such file or directory in /gg_w/www/guoguo_beta/sites/all/modules/cacherouter/Cache.php on line 124.

settings.php:

$conf['cache_inc'] = './sites/all/modules/authcache/authcache.inc';
$conf['cacherouter'] = array(
  'default' => array(
    'engine' => 'apc',
    //'server' => array(),
    //'shared' => TRUE,
    //'prefix' => '',
    //'path' => '',
    'static' => FALSE,
    'fast_cache' => FALSE,
  ),
);

I have installed authcache module.

#1

yaoweizhen - September 28, 2009 - 08:29

I also get simillar warning:


warning: unlink(/tmp/cache_lock) [function.unlink]: No such file or directory in /gg_w/www/guoguo_beta/sites/all/modules/cacherouter/Cache.php on line 124.
warning: unlink(/tmp/cache_views_lock) [function.unlink]: No such file or directory in /gg_w/www/guoguo_beta/sites/all/modules/cacherouter/Cache.php on line 124.

#2

markdia - September 30, 2009 - 15:22

I've seen a similar problem currently. Looking at possible fixes.

I've made a simple edit to the unlock method to say:

function unlock() {
if (file_exists($this->lock)) {
unlink($this->lock);
}
}
}

and it seems to remove this pesky warning from bloating the logs.

#3

Mike_Waters - October 1, 2009 - 23:35

subscribing...
My error lists /tmp/cache_content_lock
Technically, it is correct; there is no such file in /tmp.

#4

ajayg - October 7, 2009 - 04:26
Title:warning: unlink(/tmp/cache_menu_lock)» creating severe load on system by logging thousands of unlink errors in DB log
Category:support request» bug report
Priority:normal» critical

If you are using a check to see if file exists (as suggested in #2) then won't it increase diskio further decreasing performance?

I am getting same error while using APC and it creates drastic load on the server. Not because of the change you suggested, just by just installing cacherouter since it is creating hundreds of error messages in the log. I am using APC as engine.

my error is slightly different (same place line 124) but different error.
unlink(/tmp/www_-cache_filter_lock) [<a href='function.unlink'>function.unlink</a>]: No such file or directory in /var/www/vhosts/domain.com/httpdocs/sites/all/modules/cacherouter/Cache.php on line 124.

Why it is trying to unlink files when I am not using file engine at all?

#5

ajayg - October 7, 2009 - 04:31

Same error has been reported with xcache too. #575920: Xcache - unlink errors

#6

Mike_Waters - October 8, 2009 - 00:48

function unlock() {
if (file_exists($this->lock)) {
unlink($this->lock);
}
}

Even with the above change, I am getting some errors:

unlink(/tmp/cache_lock) function.unlink: No such file or directory in /<snip>/modules/cacherouter/Cache.php on line 125.

Backtrace (courtesy of drupal_tweaks module)
Backtrace: unlink(...)[Cache.php:125] <=unlock(Array)[apc.php:109] <=set(...)[CacheRouter.php:63] <=set(...)[cacherouter.inc:93] <=cache_set(...)[jq.module:50] <=jq_plugins(...)[jq.add.inc:6] <=_jq_add(...)[jq.module:34] <=jq_add(...)[twilio.module:17] <=twilio_init(Array)[:] <=call_user_func_array(...)[module.inc:471] <=module_invoke_all(...)[common.inc:2590] <=_drupal_bootstrap_full(Array)[bootstrap.inc:1326] <=_drupal_bootstrap(a:1:{i:0;i:8;})[bootstrap.inc:1209] <=drupal_bootstrap(a:1:{i:0;i:8;})[index.php:16] <=index.php

It appears that the origin of the error is a module Ive written ('twilio.module') that uses a jquery plugin invoked via the jq module, which attempts to use D6 core's cache_set, which meanders through APC (which I am obviously using) and on to the unlink error.

Is this related to the other unlink errors in the issue queue?
Is there any way to mitigate it at this time?

Thanks.

#7

ajayg - October 8, 2009 - 03:07

I do not have your twilo module still I see the error. :)

#8

Mike_Waters - October 8, 2009 - 03:13

yeah I tried to word my post ("origin" !== "culprit" ) so as not to blame my own module, ;)

#9

JirkaRybka - October 8, 2009 - 10:28

The file might be unlinked by another concurrent request right between file_exists() and unlink() - unless we use locks on deletion of files. I would try an atomic @unlink() instead.

#10

Mike_Waters - October 8, 2009 - 14:32

There is a thread on the D7 issue queue regarding the implementation of a lock system to avoid race conditions like these, using semaphores. (http://drupal.org/node/251792)
There is a patch for D6.14 (http://drupal.org/files/issues/lock-251792-224-D6.patch) that implements the locking framework and fixes a few race conditions (menu_rebuild(), and something to do with translations).
Perhaps this would be helpful in this case?

I am not sure this is a good long-term option, because it remains to be seen whether this will make it into D6 core at all.

EDIT: It is curious to me that, if this is indeed due to a race condition, that it has never been reported before - this is a type of module that should be used on a high-volume site, and one would think that this situation would occur frequently on such a site. The project that I've rolled cacherouter out on is new, and besides se spider traffic, I've had only maybe 1,000 hits in the past 5 days.

#11

ajayg - October 9, 2009 - 00:55

I don't think this is a race condition related to file unlink. Please note the issue is against APC cache. The issue is cache router is trying to unlink APC cache entry as if it was a file. And it can't because there is no file by that name.

e.g in #4 above "unlink(/tmp/www_-cache_filter_lock)", "www_-cache_filter_lock is a memory based entry in user data portion of APC not a disk based file under /tmp.

So cacherouter somehow needs to understand it is dealing with APC and should delete the cache entry instead of "unlinking" thinking it is a file. It should not even try to do any diskIO to check if the file exists since it can't exist. That is why #6 is not a solution. It will just supress the error message but 1) it won't delete the cache entry when it is supposed to and 2) unnecessarily increase disk io, negating the very reason APC is used.

#12

JirkaRybka - October 9, 2009 - 10:29

I never really used APC, but from reading the code I see, that this is quite not the case. Apart from storing actual data in APC, cache router also implements a locking mechanism to avoid collisions between concurrent requests. This is implemented with the use of dummy empty files in tmp directory (with a good descriptive names employing a "lock" suffix), and obtaining flock() locks on these. Unless APC have some native locking mechanism (I really don't know this bit), this implementation is fine. The unlink only just removes the dummy file when the lock is lifted (which is in fact just a cleanup operation, not strictly required).

#13

ajayg - October 10, 2009 - 02:31

Looking at the code I can see your point. However looking at engines/memcache.php it has own implementation of lock() and unlock() which does not use filesystem at all. So perhaps APC need similar handling of lock /unlock?

#14

ajayg - October 10, 2009 - 02:46

Ok the orginal version before rc1 , APC engine had its own locking mechanism. This was specifically deleted by this commit http://drupal.org/cvs?commit=259630
"tweaked apc/eacc/xcache to use files for locks for better reliability and true atomic locks."

see the diff
http://cvs.drupal.org/viewvc.py/drupal/contributions/modules/cacherouter...

So since it no longer has lock/unlock implementation in the file, it executes the default one from from parent class.

#15

surge_martin - October 10, 2009 - 17:46

Subscribing.

I installed Cache Router last night and was alarmed to wake up to a screen full of error messages.

I've suppressed the error messages for now, but I agree that if no call to the file system is necessary it should be avoided.

@ajayg: I'm not sure I understand. If there are files for locks, why are we all getting these messages? Is there nothing that needs to be deleted, or are there files being created but not deleted?

#16

ajayg - October 10, 2009 - 18:31

It seems the files are for lock but some how they don't exists or getting deleted somehow before cacherouter needs to delete at appropriate time. Perhaps they are not getting created as part of lock and unlock is trying to delete.

I haven't see any lock file getting created at all, but I could be just looking at wrong moment after they are deleted.

#17

toemaz-gdo - October 22, 2009 - 10:06

subscribe

#18

nquocbao - October 27, 2009 - 10:12

  function unlock() {
    if ($this->lock_fp) {
      flock($this->lock_fp, LOCK_UN);
      fclose($this->lock_fp);
      unlink($this->lock);
      $this->lock_fp = null;
    }
  }

This will fix your problem. We need to unlock the file first, close the handle and then unlink the file. I think this problem only occurs on windows system.

#19

Mike_Waters - October 28, 2009 - 16:55

Using a debian box here, still have the problem.

#20

nquocbao - October 29, 2009 - 02:40

try the fix. does it solve ur pb ?

#21

vertazzar - October 30, 2009 - 13:08

<?php $conf['cache_inc'] = './sites/all/modules/authcache/authcache.inc';
$conf['cacherouter'] = array(
 
'default' => array(
   
'engine' => 'apc',
   
//'server' => array(),
    //'shared' => TRUE,
    //'prefix' => '',
    //'path' => '',
   
'static' => FALSE,
   
'fast_cache' => FALSE,
  ),
);

?>

i see you commented the //path

why? cause cache needs to know where to store files. thats why you have error "no such file in directory" etc

#22

joshk - October 30, 2009 - 21:55

FWIW, facebook uses the pthread mutex lock option.

I've also been seeing some issues with this new locking system in place. I think the default APC file locking system is supposed to be pretty efficient.

#23

fred0 - November 2, 2009 - 22:53

I am also seeing these errors. Mostly for cache_filter_lock.

The proposed fix in #18 did not work for me. I am on a CentOS system and it gives me:
PHP Parse error: syntax error, unexpected $end, expecting T_FUNCTION in /var/www/vhosts/domain.com/httpdocs/sites/default/modules/cacherouter/Cache.php on line 131

Also, I have set my path as suggested in #21 to no avail. I am still getting errors for files in /tmp and nothing is created in the defined path.
Setting "lock_dir" (called at line 48 of Cache.php) does change the error to show the defined directory
(ie - 'lock_dir' => 'sites/default/files/filecache',). Using this I had to manually create the filecache directory. However, I still get the errors.

I am seeing the files being created and deleted from time to time though.

#24

fizk - November 5, 2009 - 21:53

Same problem here:

Warning: unlink(/tmp/cache_lock) [function.unlink]: No such file or directory in /var/www/drupal2/sites/all/modules/cacherouter/Cache.php on line 124

Cacherouter 6.x-1.0-rc1
Drupal 6.14
CentOS 5.3

#25

vertazzar - November 6, 2009 - 10:26

change the path for cache it may work then.

#26

nquocbao - November 16, 2009 - 10:45

@fred it looks like a parse error, maybe you don't update the code properly ?

#27

blackdog - November 20, 2009 - 08:28

We're seing this too. Is the maintainer available for a reply?

#28

ajayg - November 20, 2009 - 13:35

Unfortunately maintainer hasn't replied for two months.

 
 

Drupal is a registered trademark of Dries Buytaert.