Edit report at https://bugs.php.net/bug.php?id=54612&edit=1
ID: 54612 Updated by: yohg...@php.net Reported by: erno dot kovacs at freemail dot hu Summary: random Error 404 -Status: Open +Status: Feedback Type: Bug Package: Scripting Engine problem Operating System: Linux PHP Version: 5.3.6 Block user comment: N Private report: N New Comment: Do you still have problem with 5.4 or later? Previous Comments: ------------------------------------------------------------------------ [2011-10-08 14:33:59] f...@php.net This is not related to FPM. I move this bug to core. ------------------------------------------------------------------------ [2011-09-07 16:28:41] erno dot kovacs at freemail dot hu php_resolve_path is being called with the correct filename, which is /web/web/xxxxxx/index.php this time, and at the tsrm_realpath() call and then it fails somewhere in virtual_file_ex, where it failes at this block: add_slash = (use_realpath != CWD_REALPATH) && path_length > 0 && IS_SLASH(resolved_path[path_length-1]); t = CWDG(realpath_cache_ttl) ? 0 : -1; path_length = tsrm_realpath_r(resolved_path, start, path_length, &ll, &t, use_realpath, 0, NULL TSRMLS_CC); if (path_length < 0) { errno = ENOENT; mydebug("VFEX FAILURE #444"); return 1; } i dont want to dig any deeper, please give me some hints. ------------------------------------------------------------------------ [2011-09-07 15:47:50] erno dot kovacs at freemail dot hu Added a few lines of dummy debug info into fopen_wrappers's php_fopen_primary_script, and when it fails, it fails at zend_resolve_path(), which returns NULL. ------------------------------------------------------------------------ [2011-09-07 15:13:24] erno dot kovacs at freemail dot hu got the same issue on another box (debian lenny this time, not squeeze) with php 5.3.8, here are the logs: when its ok: # strace -s 1024 -p 27057 Process 27057 attached - interrupt to quit accept(0, {sa_family=AF_INET, sin_port=htons(47532), sin_addr=inet_addr("127.0.0.1")}, [16]) = 4 clock_gettime(CLOCK_MONOTONIC, {67474521, 156597098}) = 0 time(NULL) = 1315407924 times({tms_utime=37, tms_stime=14, tms_cutime=0, tms_cstime=0}) = -123996470 poll([{fd=4, events=POLLIN}], 1, 5000) = 1 ([{fd=4, revents=POLLIN}]) read(4, "\1\1\0\1\0\10\0\0"..., 8) = 8 read(4, "\0\1\0\0\0\0\0\0"..., 8) = 8 read(4, "\1\4\0\1\3\2\0\0"..., 8) = 8 read(4, "\17\17SERVER_SOFTWARElighttpd/1.4.29\v\nSERVER_NAMExxxxxx.com\21\7GATEWAY_INTERFACECGI/1.1\v\5SERVER_PORT50001\v\fSERVER_ADDR217.13.99.87\v\5REMOTE_PORT51194\v\fREMOTE_ADDR80.98.95.222\v\nSCRIPT_NAME/index.php\t\0PATH_INFO\17\31SCRIPT_FILENAME/web/web/xxxxxx/index.php\r\20DOCUMENT_ROOT/web/web/xxxxxx/\v\1REQUEST_URI/\f\0QUERY_STRING\16\3REQUEST_METHODGET\17\3REDIRECT_STATUS200\17\10SERVER_PROTOCOLHTTP/1.1\t\20HTTP_HOSTxxxxxx.com:50001\17JHTTP_USER_AGENTMozilla/5.0 (Windows NT 6.1; WOW64; rv:6.0.1) Gecko/20100101 Firefox/6.0.1\v?HTTP_ACCEPTtext/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8\24#HTTP_ACCEPT_LANGUAGEhu-hu,hu;q=0.8,en-us;q=0.5,en;q=0.3\24\rHTTP_ACCEPT_ENCODINGgzip, deflate\23\36HTTP_ACCEPT_CHARSETISO-8859-2,utf-8;q=0.7,*;q=0.7\10\1HTTP_DNT1\17\nHTTP_CONNECTIONkeep-alive\22\tHTTP_CACHE_CONTROLmax-age=0"..., 770) = 770 read(4, "\1\4\0\1\0\0\0\0"..., 8) = 8 clock_gettime(CLOCK_MONOTONIC, {67474521, 161587774}) = 0 time(NULL) = 1315407924 setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={60, 0}}, NULL) = 0 rt_sigaction(SIGPROF, {0x8229650, [PROF], SA_RESTART}, {0x8229650, [PROF], SA_RESTART}, 8) = 0 rt_sigprocmask(SIG_UNBLOCK, [PROF], NULL, 8) = 0 time(NULL) = 1315407924 lstat64("/web/web/xxxxxx/index.php", {st_mode=S_IFREG|0644, st_size=7076, ...}) = 0 lstat64("/web/web/xxxxxx", {st_mode=S_IFDIR|0755, st_size=108, ...}) = 0 lstat64("/web/web", {st_mode=S_IFLNK|0777, st_size=1, ...}) = 0 readlink("/web/web", "/"..., 4096) = 1 open("/xxxxxx/index.php", O_RDONLY) = 5 fstat64(5, {st_mode=S_IFREG|0644, st_size=7076, ...}) = 0 clock_gettime(CLOCK_MONOTONIC, {67474521, 168395023}) = 0 getcwd("/"..., 4095) = 2 chdir("/web/web/xxxxxx") = 0 setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={120, 0}}, NULL) = 0 ioctl(5, SNDCTL_TMR_TIMEBASE or TCGETS, 0xbfa293b8) = -1 ENOTTY (Inappropriate ioctl for device) fstat64(5, {st_mode=S_IFREG|0644, st_size=7076, ...}) = 0 mmap2(NULL, 7108, PROT_READ, MAP_PRIVATE, 5, 0) = 0xb5168000 fstat64(5, {st_mode=S_IFREG|0644, st_size=7076, ...}) = 0 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb5167000 _llseek(5, 0, [0], SEEK_CUR) = 0 munmap(0xb5168000, 7076) = 0 close(5) = 0 munmap(0xb5167000, 4096) = 0 chdir("/") = 0 clock_gettime(CLOCK_MONOTONIC, {67474521, 176554306}) = 0 times({tms_utime=38, tms_stime=14, tms_cutime=0, tms_cstime=0}) = -123996468 write(4, "\1\6\0\1\0229\7\0Content-type: text/html\r\n\r\n<!DOCTYPE html PUBLIC \"-//W3C//DTD XHTML 1.0 Transitional//EN\" \"http://www.w3.org/TR/xhtml1/DTD/xhtml1-transitional.dtd\">\r\n<html xmlns=\"http://www.w3.org/1999/xhtml\">\r\n<head>\r\n<meta http-equiv=\"Content-Type\" content=\"text/html; charset=iso-8859-2\" />\r\n<title>xxxxxx.com</title>\r\n<style type=\"text/css\">\r\n<!--\r\nbody,td,th {\r\n\tfont-family: Arial, Helvetica, sans-serif;\r\n\tfont-size: 12px;\r\n\tcolor: #000000;\r\n}\r\nbody {\r\n\tbackground-color: #FFFFFF;\r\n\tcolor: #000000;\r\n\tmargin-left: 0px;\r\n\tmargin-top: 0px;\r\n\tmargin-right: 0px;\r\n\tmargin-bottom: 0px;\r\n}\r\na:link {\r\n\tcolor: #000000;\r\n}\r\na:visited {\r\n\tcolor: #000000;\r\n}\r\na:hover {\r\n\tcolor: #000000;\r\n}\r\na:active {\r\n\tcolor: #000000;\r\n}\r\na {\r\n\tfont-family: Arial, Helvetica, sans-serif;\r\n\tfont-size: 12px;\r\n}\r\ndiv.title {\r\n\tbackground-color:#1543A5;\r\n\theight:109px;\r\n}\r\n\r\ndiv.content {\r\ n\tmargin-left:50px;\r\n\tmargin-right:50px;\r\n}\r\n\r\ndiv.message {\r\n\ttext-align:center;\r\n\theight:50px;\r\n}\r\n\r\ndiv.form {\r\n\twidth:400px;\r\n\tmargin:auto;\r\n\ttext-align:center"..., 4696) = 4696 shutdown(4, 1 /* send */) = 0 recv(4, "\1\5\0\1\0\0\0\0"..., 8, 0) = 8 recv(4, ""..., 8, 0) = 0 close(4) = 0 clock_gettime(CLOCK_MONOTONIC, {67474521, 181188404}) = 0 setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0 clock_gettime(CLOCK_MONOTONIC, {67474521, 182245449}) = 0 when its 404: accept(0, {sa_family=AF_INET, sin_port=htons(47694), sin_addr=inet_addr("127.0.0.1")}, [16]) = 4 clock_gettime(CLOCK_MONOTONIC, {67474603, 177424184}) = 0 time(NULL) = 1315408006 times({tms_utime=3, tms_stime=2, tms_cutime=0, tms_cstime=0}) = -123988268 poll([{fd=4, events=POLLIN}], 1, 5000) = 1 ([{fd=4, revents=POLLIN}]) read(4, "\1\1\0\1\0\10\0\0"..., 8) = 8 read(4, "\0\1\0\0\0\0\0\0"..., 8) = 8 read(4, "\1\4\0\1\0037\0\0"..., 8) = 8 read(4, "\17\17SERVER_SOFTWARElighttpd/1.4.29\v\tSERVER_NAMExxxxxx.com\21\7GATEWAY_INTERFACECGI/1.1\v\5SERVER_PORT50001\v\fSERVER_ADDR217.13.99.88\v\5REMOTE_PORT51234\v\fREMOTE_ADDR80.98.95.222\v\nSCRIPT_NAME/index.php\t\0PATH_INFO\17\31SCRIPT_FILENAME/web/web/xxxxxx/index.php\r\20DOCUMENT_ROOT/web/web/xxxxxx/\v\1REQUEST_URI/\f\0QUERY_STRING\16\3REQUEST_METHODGET\17\3REDIRECT_STATUS200\17\10SERVER_PROTOCOLHTTP/1.1\t\17HTTP_HOSTxxxxxx.com:50001\17JHTTP_USER_AGENTMozilla/5.0 (Windows NT 6.1; WOW64; rv:6.0.1) Gecko/20100101 Firefox/6.0.1\v?HTTP_ACCEPTtext/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8\24#HTTP_ACCEPT_LANGUAGEhu-hu,hu;q=0.8,en-us;q=0.5,en;q=0.3\24\rHTTP_ACCEPT_ENCODINGgzip, deflate\23\36HTTP_ACCEPT_CHARSETISO-8859-2,utf-8;q=0.7,*;q=0.7\v*HTTP_COOKIEPHPSESSID=4c227cf6957666996f470742c77ef6df\10\1HTTP_DNT1\17\nHTTP_CONNECTIONkeep-alive\22\tHTTP_CACHE_CONTROLmax-age=0"..., 823) = 823 read(4, "\1\4\0\1\0\0\0\0"..., 8) = 8 clock_gettime(CLOCK_MONOTONIC, {67474603, 182194605}) = 0 time(NULL) = 1315408006 setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={60, 0}}, NULL) = 0 rt_sigaction(SIGPROF, {0x8229650, [PROF], SA_RESTART}, {0x8229650, [PROF], SA_RESTART}, 8) = 0 rt_sigprocmask(SIG_UNBLOCK, [PROF], NULL, 8) = 0 time(NULL) = 1315408006 lstat64("/web/web/xxxxxx/index.php", {st_mode=S_IFREG|0644, st_size=210, ...}) = 0 lstat64("/web/web/xxxxxx", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0 clock_gettime(CLOCK_MONOTONIC, {67474603, 186697702}) = 0 times({tms_utime=3, tms_stime=2, tms_cutime=0, tms_cstime=0}) = -123988267 write(4, "\1\6\0\1\0K\5\0Status: 404 Not Found\r\nContent-type: text/html\r\n\r\nNo input file specified.\n\0\0\0\0\0\1\3\0\1\0\10\0\0\0\0\0\0\0tp:"..., 104) = 104 shutdown(4, 1 /* send */) = 0 recv(4, "\1\5\0\1\0\0\0\0"..., 8, 0) = 8 recv(4, ""..., 8, 0) = 0 close(4) = 0 clock_gettime(CLOCK_MONOTONIC, {67474603, 191688504}) = 0 setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0 clock_gettime(CLOCK_MONOTONIC, {67474603, 192740671}) = 0 strangely, cgi.fix_pathinfo = 0 doesnt affect the behaviour this time. ------------------------------------------------------------------------ [2011-07-05 17:30:51] f...@php.net Not enough information was provided for us to be able to handle this bug. Please re-read the instructions at http://bugs.php.net/how-to-report.php If you can provide more information, feel free to add it to this bug and change the status back to "Open". Thank you for your interest in PHP. can you please catch the content of the request made from your webserver (lighthttpd or nginx) to FPM. You can use the strace command you used but just add -s 1024 or something big in order to ensure to see what FPM reads from the socket. You can also use tcpdump tcpdump -i any -s 0 -X dst port 9001 IMO the tcpdump option is the easier to implement. ------------------------------------------------------------------------ The remainder of the comments for this report are too long. To view the rest of the comments, please view the bug report online at https://bugs.php.net/bug.php?id=54612 -- Edit this bug report at https://bugs.php.net/bug.php?id=54612&edit=1