PHP unlink cannot delete file
· August 2, 2011 at 03:48:35
· Filed under In English, Open source, Software development
· 
Print
How I fixed a PHP’s unlink function problem in my development server using strace to debug PHP…
and why libtrash should not be used by the Apache user.
Since 2004 my development server have been having a weird problem. Sometimes, in PHP, the unlink functions starts to fail. It fails to delete some files. The permissions were right. The files were not locked. It just failed. In some older versions of PHP, unlink even returned true (meaning it successfully deleted the file) while displaying a warning saying: Warning: unlink(FileName) [function.unlink]: Success in ScriptName on line X. Yeah, it says success in a warning.
The first time it happened I was really puzzled. I spent two days trying to figure out what was the problem. I searched high and low the web for similar problems but found nothing. Was I the only person with this problem? Maybe, I thought. My development server is a Slackware server with too many customized applications and version combinations not found in other distributions. With so much customization (configuration, kernel, software versions) this Slackware version is now unique and its problems are sometimes unique too. So, the problem could be anywhere from the higher parts of the web stack (Apache and PHP) to the lower parts like the C library or the kernel. And that’s why I also didn’t send a bug report in PHP: I was not sure this was a PHP problem.
Anyway, I found rebooting fixed the problem. Of course I didn’t try to reboot to fix it (c’mon, this is not Windows), but since I was recompiling the kernel to test different file system options, I needed to reboot. Because of its sporadic nature, I could not replicate the problem at will, sometimes it appeared again after weeks or months. I started to learn to live with it.
So, last Monday it happened again. After almost 7 years, here I was again, facing this unlink which refused to delete and yet it claimed success. I decided I was going to find the cause today. So I decided to do what I should have done before: I will debug PHP.
But before recompiling PHP with debug information and using gdb, I decided to start with something easier: strace.
This is what I did:
Step 1: I created a test PHP script:
unlink ("/home/mvaldez/SHARE/DEV-www/eclipse/inovman2old/backups/backup_20110801_100336_dump.txt.bz2");
Step 2: I stopped Apache.
/etc/rc.d/rc.httpd stop
Step 3: I started Apache in debug mode:
/usr/apache/bin/apachectl -X
Step 4: I used ps to find out what is the PID of the httpd process:
ps auxw | grep http nobody 25908 1.4 0.1 242360 14360 pts/1 S+ 14:20 0:00 /usr/apache/bin/httpd -X root 26529 0.0 0.0 8720 744 pts/2 R+ 14:20 0:00 grep http
Step 5: I started strace attached to that process:
strace -p 25908
Process 25908 attached - interrupt to quit
epoll_wait(16, {{EPOLLIN, {u32=19153432, u64=19153432}}}, 2, 4294967295) = 1
Step 6: In my workstation, I launched links, a text-only web browser (I could have used lynx, wget or even a graphical web browser).
links http://192.168.246.1/dev/dev/testfiles/unlinktest/u.php
I received the usual message:
Warning: unlink(/home/mvaldez/SHARE/DEV-www/eclipse/inovman2old/backups/backup_20110801_100336_dump.txt.bz2)
[function.unlink]: Success in /home/mvaldez/SHARE/DEV-www/testfiles/unlinktest/u.php on line 3
And this was the strace output (note the highlighted lines):
accept(4, {sa_family=AF_INET6, sin6_port=htons(52039), inet_pton(AF_INET6, "::ffff:192.168.246.25", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, [28]) = 17
fcntl(17, F_GETFD) = 0
fcntl(17, F_SETFD, FD_CLOEXEC) = 0
semop(2555917, 0x7f9a88b8deec, 1) = 0
getsockname(17, {sa_family=AF_INET6, sin6_port=htons(80), inet_pton(AF_INET6, "::ffff:192.168.246.1", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, [68719476764]) = 0
fcntl(17, F_GETFL) = 0x2 (flags O_RDWR)
fcntl(17, F_SETFL, O_RDWR|O_NONBLOCK) = 0
read(17, "GET /dev/testfiles/unlinktest/u.p"..., 8000) = 669
stat("/home/mvaldez/SHARE/DEV-www/testfiles/unlinktest/u.php", {st_mode=S_IFREG|0744, st_size=113, ...}) = 0
open("/.htaccess", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/home/.htaccess", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/home/mvaldez/.htaccess", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/home/mvaldez/SHARE/.htaccess", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/home/mvaldez/SHARE/DEV-www/.htaccess", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/home/mvaldez/SHARE/DEV-www/testfiles/.htaccess", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/home/mvaldez/SHARE/DEV-www/testfiles/unlinktest/.htaccess", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/home/mvaldez/SHARE/DEV-www/testfiles/unlinktest/u.php/.htaccess", O_RDONLY|O_CLOEXEC) = -1 ENOTDIR (Not a directory)
setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={60, 0}}, NULL) = 0
rt_sigaction(SIGPROF, {0x7f9a81552ec0, [PROF], SA_RESTORER|SA_RESTART, 0x7f9a87bc2f30}, {0x7f9a81552ec0, [PROF], SA_RESTORER|SA_RESTART, 0x7f9a87bc2f30}, 8) = 0
rt_sigprocmask(SIG_UNBLOCK, [PROF], NULL, 8) = 0
rt_sigaction(SIGSEGV, {0x7f9a7e27bd60, [SEGV], SA_RESTORER|SA_RESTART, 0x7f9a87bc2f30}, {SIG_DFL, [SEGV], SA_RESTORER|SA_RESTART, 0x7f9a87bc2f30}, 8) = 0
rt_sigaction(SIGFPE, {0x7f9a7e27bd60, [FPE], SA_RESTORER|SA_RESTART, 0x7f9a87bc2f30}, {SIG_DFL, [FPE], SA_RESTORER|SA_RESTART, 0x7f9a87bc2f30}, 8) = 0
rt_sigaction(SIGBUS, {0x7f9a7e27bd60, [BUS], SA_RESTORER|SA_RESTART, 0x7f9a87bc2f30}, {SIG_DFL, [BUS], SA_RESTORER|SA_RESTART, 0x7f9a87bc2f30}, 8) = 0
rt_sigaction(SIGILL, {0x7f9a7e27bd60, [ILL], SA_RESTORER|SA_RESTART, 0x7f9a87bc2f30}, {SIG_DFL, [ILL], SA_RESTORER|SA_RESTART, 0x7f9a87bc2f30}, 8) = 0
rt_sigaction(SIGABRT, {0x7f9a7e27bd60, [ABRT], SA_RESTORER|SA_RESTART, 0x7f9a87bc2f30}, {SIG_DFL, [ABRT], SA_RESTORER|SA_RESTART, 0x7f9a87bc2f30}, 8) = 0
getcwd("/home/mvaldez/SHARE/DEV-www/testfiles/unlinktest"..., 4095) = 49
chdir("/home/mvaldez/SHARE/DEV-www/testfiles/unlinktest") = 0
setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={30, 0}}, NULL) = 0
open("/home/mvaldez/SHARE/DEV-www/testfiles/unlinktest/u.php", O_RDONLY) = 18
fstat(18, {st_mode=S_IFREG|0744, st_size=113, ...}) = 0
mmap(NULL, 113, PROT_READ, MAP_SHARED, 18, 0) = 0x7f9a8a671000
munmap(0x7f9a8a671000, 113) = 0
close(18) = 0
stat("/home/mvaldez/SHARE/DEV-www/testfiles/unlinktest/u.php", {st_mode=S_IFREG|0744, st_size=113, ...}) = 0
stat("/home/mvaldez/SHARE/DEV-www/testfiles/unlinktest/u.php", {st_mode=S_IFREG|0744, st_size=113, ...}) = 0
write(2, "EACCELERATOR hit: \"/home/mvaldez/"..., 75) = 75
geteuid() = 99
open("/etc/passwd", O_RDONLY|O_CLOEXEC) = 18
lseek(18, 0, SEEK_CUR) = 0
fstat(18, {st_mode=S_IFREG|0644, st_size=1959, ...}) = 0
mmap(NULL, 1959, PROT_READ, MAP_SHARED, 18, 0) = 0x7f9a8a671000
lseek(18, 1959, SEEK_SET) = 1959
munmap(0x7f9a8a671000, 1959) = 0
close(18) = 0
open("//.libtrash", O_RDONLY) = -1 ENOENT (No such file or directory)
geteuid() = 99
open("/etc/passwd", O_RDONLY|O_CLOEXEC) = 18
lseek(18, 0, SEEK_CUR) = 0
fstat(18, {st_mode=S_IFREG|0644, st_size=1959, ...}) = 0
mmap(NULL, 1959, PROT_READ, MAP_SHARED, 18, 0) = 0x7f9a8a671000
lseek(18, 1959, SEEK_SET) = 1959
munmap(0x7f9a8a671000, 1959) = 0
close(18) = 0
geteuid() = 99
open("/etc/passwd", O_RDONLY|O_CLOEXEC) = 18
lseek(18, 0, SEEK_CUR) = 0
fstat(18, {st_mode=S_IFREG|0644, st_size=1959, ...}) = 0
mmap(NULL, 1959, PROT_READ, MAP_SHARED, 18, 0) = 0x7f9a8a671000
lseek(18, 1959, SEEK_SET) = 1959
munmap(0x7f9a8a671000, 1959) = 0
close(18) = 0
stat("//Recycled", 0x7fff717bb300) = -1 ENOENT (No such file or directory)
mkdir("//Recycled", 0700) = -1 EACCES (Permission denied)
write(2, "[Mon Aug 01 14:28:26 2011] [error"..., 298) = 298
chdir("/home/mvaldez/SHARE/DEV-www/testfiles/unlinktest") = 0
rt_sigaction(SIGSEGV, {SIG_DFL, [SEGV], SA_RESTORER|SA_RESTART, 0x7f9a87bc2f30}, {0x7f9a7e27bd60, [SEGV], SA_RESTORER|SA_RESTART, 0x7f9a87bc2f30}, 8) = 0
rt_sigaction(SIGFPE, {SIG_DFL, [FPE], SA_RESTORER|SA_RESTART, 0x7f9a87bc2f30}, {0x7f9a7e27bd60, [FPE], SA_RESTORER|SA_RESTART, 0x7f9a87bc2f30}, 8) = 0
rt_sigaction(SIGBUS, {SIG_DFL, [BUS], SA_RESTORER|SA_RESTART, 0x7f9a87bc2f30}, {0x7f9a7e27bd60, [BUS], SA_RESTORER|SA_RESTART, 0x7f9a87bc2f30}, 8) = 0
rt_sigaction(SIGILL, {SIG_DFL, [ILL], SA_RESTORER|SA_RESTART, 0x7f9a87bc2f30}, {0x7f9a7e27bd60, [ILL], SA_RESTORER|SA_RESTART, 0x7f9a87bc2f30}, 8) = 0
rt_sigaction(SIGABRT, {SIG_DFL, [ABRT], SA_RESTORER|SA_RESTART, 0x7f9a87bc2f30}, {0x7f9a7e27bd60, [ABRT], SA_RESTORER|SA_RESTART, 0x7f9a87bc2f30}, 8) = 0
open("/dev/urandom", O_RDONLY) = 18
read(18, "\361\303C\"\255\337Cs"..., 8) = 8
close(18) = 0
open("/dev/urandom", O_RDONLY) = 18
read(18, "l!3\273]Y\356\231"..., 8) = 8
close(18) = 0
open("/dev/urandom", O_RDONLY) = 18
read(18, "kHNK\303\277\37#"..., 8) = 8
close(18) = 0
setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0
writev(17, [{"HTTP/1.1 200 OK\r\nDate: Mon, 01 Au"..., 279}, {"<br />\n<b>Warning</b>: unlink(/h"..., 269}], 2) = 548
read(17, 0x1257208, 8000) = -1 EAGAIN (Resource temporarily unavailable)
write(9, "192.168.246.25 - - [01/Aug/2011:1"..., 103) = 103
write(10, "referer\n"..., 8) = 8
write(11, "agent\n"..., 6) = 6
write(12, "192.168.246.25 - - [01/Aug/2011:1"..., 161) = 161
poll([{fd=17, events=POLLIN}], 1, 15000
The call to the libc unlink never happened, instead we can see a failed attempt to read a .libtrash directory and then create a Recycled directory in the home directory of the Apache user (which in this server is the user nobody, which home is the file system root /). Ok, now it makes sense: the .libtrash directory is the configuration directory of libtrash (http://pages.stern.nyu.edu/~marriaga/software/libtrash/), a library for Linux which can be preloaded to intercept calls to GNU libc unlink (among other functions) so that deleted files are moved to a trash can directory from where you can recover deleted files if you wish. The Recycled directory is the name of the trash can directory as configured in this server.
Soooo, my hypothesis by now was that libtrash was intercepting the call to libc unlink made by PHP but then failed, because the nobody user has no appropriate home directory.
Step 7: As the loading of the libtrash is done in /etc/profile.d/default.sh (in this server) for all users by exporting the LD_PRELOAD variable, to test I just need to unset it in my current session and then load Apache again:
unset LD_PRELOAD /usr/apache/bin/apachectl -X
Step 8: Now, let’s run strace and reload the PHP script. This was the strace output now (note the highlighted line):
Process 18951 attached - interrupt to quit
epoll_wait(16, {{EPOLLIN, {u32=34029016, u64=34029016}}}, 2, 4294967295) = 1
accept(4, {sa_family=AF_INET6, sin6_port=htons(35245), inet_pton(AF_INET6, "::ffff:192.168.246.25", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, [140733193388060]) = 17
fcntl(17, F_GETFD) = 0
fcntl(17, F_SETFD, FD_CLOEXEC) = 0
semop(2752525, 0x7eff72b37eec, 1) = 0
getsockname(17, {sa_family=AF_INET6, sin6_port=htons(80), inet_pton(AF_INET6, "::ffff:192.168.246.1", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, [68719476764]) = 0
fcntl(17, F_GETFL) = 0x2 (flags O_RDWR)
fcntl(17, F_SETFL, O_RDWR|O_NONBLOCK) = 0
read(17, "GET /dev/testfiles/unlinktest/u.p"..., 8000) = 626
stat("/home/mvaldez/SHARE/DEV-www/testfiles/unlinktest/u.php", {st_mode=S_IFREG|0744, st_size=113, ...}) = 0
open("/.htaccess", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/home/.htaccess", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/home/mvaldez/.htaccess", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/home/mvaldez/SHARE/.htaccess", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/home/mvaldez/SHARE/DEV-www/.htaccess", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/home/mvaldez/SHARE/DEV-www/testfiles/.htaccess", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/home/mvaldez/SHARE/DEV-www/testfiles/unlinktest/.htaccess", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/home/mvaldez/SHARE/DEV-www/testfiles/unlinktest/u.php/.htaccess", O_RDONLY|O_CLOEXEC) = -1 ENOTDIR (Not a directory)
mmap(NULL, 528384, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7eff74392000
setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={60, 0}}, NULL) = 0
rt_sigaction(SIGPROF, {0x7eff6b4fcec0, [PROF], SA_RESTORER|SA_RESTART, 0x7eff71b6cf30}, {SIG_DFL, [], 0}, 8) = 0
rt_sigprocmask(SIG_UNBLOCK, [PROF], NULL, 8) = 0
rt_sigaction(SIGSEGV, {0x7eff68225d60, [SEGV], SA_RESTORER|SA_RESTART, 0x7eff71b6cf30}, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGFPE, {0x7eff68225d60, [FPE], SA_RESTORER|SA_RESTART, 0x7eff71b6cf30}, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGBUS, {0x7eff68225d60, [BUS], SA_RESTORER|SA_RESTART, 0x7eff71b6cf30}, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGILL, {0x7eff68225d60, [ILL], SA_RESTORER|SA_RESTART, 0x7eff71b6cf30}, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGABRT, {0x7eff68225d60, [ABRT], SA_RESTORER|SA_RESTART, 0x7eff71b6cf30}, {SIG_DFL, [], 0}, 8) = 0
getcwd("/root"..., 4095) = 6
chdir("/home/mvaldez/SHARE/DEV-www/testfiles/unlinktest") = 0
setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={30, 0}}, NULL) = 0
open("/home/mvaldez/SHARE/DEV-www/testfiles/unlinktest/u.php", O_RDONLY) = 18
fstat(18, {st_mode=S_IFREG|0744, st_size=113, ...}) = 0
mmap(NULL, 113, PROT_READ, MAP_SHARED, 18, 0) = 0x7eff74391000
munmap(0x7eff74391000, 113) = 0
close(18) = 0
stat("/home/mvaldez/SHARE/DEV-www/testfiles/unlinktest/u.php", {st_mode=S_IFREG|0744, st_size=113, ...}) = 0
open("/tmp/eaccelerator/4/3/eaccelerator-9032.9315914", O_RDONLY) = -1 ENOENT (No such file or directory)
lstat("/home/mvaldez/SHARE/DEV-www/testfiles/unlinktest/u.php", {st_mode=S_IFREG|0744, st_size=113, ...}) = 0
lstat("/home/mvaldez/SHARE/DEV-www/testfiles/unlinktest", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/home/mvaldez/SHARE/DEV-www/testfiles", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/home/mvaldez/SHARE/DEV-www", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/home/mvaldez/SHARE", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/home/mvaldez", {st_mode=S_IFDIR|0711, st_size=4096, ...}) = 0
lstat("/home", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
open("/home/mvaldez/SHARE/DEV-www/testfiles/unlinktest/u.php", O_RDONLY) = 18
fstat(18, {st_mode=S_IFREG|0744, st_size=113, ...}) = 0
fstat(18, {st_mode=S_IFREG|0744, st_size=113, ...}) = 0
fstat(18, {st_mode=S_IFREG|0744, st_size=113, ...}) = 0
mmap(NULL, 113, PROT_READ, MAP_SHARED, 18, 0) = 0x7eff74391000
unlink("/tmp/eaccelerator/4/3/eaccelerator-9032.9315914") = -1 ENOENT (No such file or directory)
open("/tmp/eaccelerator/4/3/eaccelerator-9032.9315914", O_WRONLY|O_CREAT|O_EXCL, 0600) = -1 ENOENT (No such file or directory)
write(2, "EACCELERATOR: Open for write fail"..., 117) = 117
write(2, "EACCELERATOR cached: \"/home/mvald"..., 78) = 78
munmap(0x7eff74391000, 113) = 0
close(18) = 0
unlink("/home/mvaldez/SHARE/DEV-www/eclipse/inovman2old/backups/backup_20110801_100336_dump.txt.bz2") = 0
chdir("/root") = -1 EACCES (Permission denied)
rt_sigaction(SIGSEGV, {SIG_DFL, [SEGV], SA_RESTORER|SA_RESTART, 0x7eff71b6cf30}, {0x7eff68225d60, [SEGV], SA_RESTORER|SA_RESTART, 0x7eff71b6cf30}, 8) = 0
rt_sigaction(SIGFPE, {SIG_DFL, [FPE], SA_RESTORER|SA_RESTART, 0x7eff71b6cf30}, {0x7eff68225d60, [FPE], SA_RESTORER|SA_RESTART, 0x7eff71b6cf30}, 8) = 0
rt_sigaction(SIGBUS, {SIG_DFL, [BUS], SA_RESTORER|SA_RESTART, 0x7eff71b6cf30}, {0x7eff68225d60, [BUS], SA_RESTORER|SA_RESTART, 0x7eff71b6cf30}, 8) = 0
rt_sigaction(SIGILL, {SIG_DFL, [ILL], SA_RESTORER|SA_RESTART, 0x7eff71b6cf30}, {0x7eff68225d60, [ILL], SA_RESTORER|SA_RESTART, 0x7eff71b6cf30}, 8) = 0
rt_sigaction(SIGABRT, {SIG_DFL, [ABRT], SA_RESTORER|SA_RESTART, 0x7eff71b6cf30}, {0x7eff68225d60, [ABRT], SA_RESTORER|SA_RESTART, 0x7eff71b6cf30}, 8) = 0
munmap(0x7eff74392000, 528384) = 0
open("/dev/urandom", O_RDONLY) = 18
read(18, "\323\342\363\30\262\277\266\4"..., 8) = 8
close(18) = 0
open("/dev/urandom", O_RDONLY) = 18
read(18, "X\364]:\33W\27\31"..., 8) = 8
close(18) = 0
open("/dev/urandom", O_RDONLY) = 18
read(18, "\245\201\317H\204\264\374,"..., 8) = 8
close(18) = 0
setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0
writev(17, [{"HTTP/1.1 200 OK\r\nDate: Mon, 01 Au"..., 277}], 1) = 277
read(17, 0x207ddd8, 8000) = -1 EAGAIN (Resource temporarily unavailable)
write(9, "192.168.246.25 - - [01/Aug/2011:1"..., 101) = 101
write(10, "referer\n"..., 8) = 8
write(11, "agent\n"..., 6) = 6
write(12, "192.168.246.25 - - [01/Aug/2011:1"..., 159) = 159
poll([{fd=17, events=POLLIN}], 1, 15000) =
Success! Great, after 7 years I finally found out the cause of this.
So now, the real fix is to make libtrash to load for regular users but not the nobody user (or root, as root is the one launching rc.httpd when booting).
Step 9: So, in /etc/profile.d/default.sh I changed this:
export LD_PRELOAD=/usr/local/lib/libtrash.so
to this:
if [ $(/bin/id -g) -eq 100 ] ; then export LD_PRELOAD=/usr/local/lib/libtrash.so fi
In this way only users from the group with GID 100 (regular users in this server) will have libtrash preloaded.
The funny thing is: in the README file of libtrash there is note about this problem. I missed it because in the first libtrash version I used (2.3) there was not such a note. And I upgraded libtrash only when upgraded Slackware versions (2.8, then 3.2) by just recompiling and installing the latest version, didn’t pay too much attention to the latest notes in the README file.
This is the note:
IMPORTANT NOTE 3: If you are running a web (or other) server as user
nobody, then you should ensure that libtrash is not active for that
process. The issue is that by default libtrash refuses to remove files if
it will not be able to save them in that user’s trash can. The nobody
account typically lacks a (writable) home directory; as such, when processes
run as nobody try to remove a file, libtrash will always make that
operation fail. For that reason, always start servers run through the
noboby account (or any other, low privileges account missing a writable
home dir) with libtrash disabled (just prefix “LD_PRELOAD= ” to the command
line). (My thanks to Nicola Fontana for pointing this out!)
Hope this help somebody else.
Still, I cannot explain why this problem only happened sometimes, not always. I expected to libtrash to do its stuff (and fail) always. My theory is that when Slackware boots the root user who runs the rc.httpd script doesn’t have the LD_PRELOAD variable set, so libtrash is not intercepting for Apache; however, if I login into the server and restart Apache, my session has LD_PRELOAD set and now libtrash is intercepting all unlink calls from Apache/PHP (however I didn’t check this).
As a side note, you can see other interesting things in the strace output, like Apache checking every directory in the path for .htaccess files, or eaccelerator looking for a precompiled version of the script, etc. It makes me wonder if moving the web directory higher (closer to the file system root) would make Apache to serve pages faster.
I learned today:
- When bulding your applications yourself, always read the relese notes when upgrading.
- It is easy to use strace to see what is going on inside PHP.
- Intercepting function calls of third party programs can have unexpected results (specially if something goes wrong).
Sometimes I envy people with vanilla Linux setups… but only for a few seconds.