Re: [PHP] Re: Slow sessions.
On 3/28/2011 3:40 PM, Bostjan Skufca wrote: Great, please report back if/when you discover the cause. After searching for some information about the error messages I was getting on the file server, I found this: http://www.spinics.net/lists/linux-nfs/msg14679.html I ran 'server nfslock status', and it wasn't even running (rpcbind wasn't recognized as a service). So I started the nfslock service and it immediately fixed the problem. I checked the config, and the service wasn't set to start in level 3, so I turned that on. It's been running for over 24 hours now with no problems. Thanks again Bostjan for the help. I don't think I could have narrowed down the problem without using the strace. -- Rob -- PHP General Mailing List (http://www.php.net/) To unsubscribe, visit: http://www.php.net/unsub.php
Re: [PHP] Re: Slow sessions.
Nice of you to post the resolution of your problem. Glad to hear it is fixed now. Take care, b. On 30 March 2011 17:46, Rob Adams rad...@circlepix.com wrote: On 3/28/2011 3:40 PM, Bostjan Skufca wrote: Great, please report back if/when you discover the cause. After searching for some information about the error messages I was getting on the file server, I found this: http://www.spinics.net/lists/linux-nfs/msg14679.html I ran 'server nfslock status', and it wasn't even running (rpcbind wasn't recognized as a service). So I started the nfslock service and it immediately fixed the problem. I checked the config, and the service wasn't set to start in level 3, so I turned that on. It's been running for over 24 hours now with no problems. Thanks again Bostjan for the help. I don't think I could have narrowed down the problem without using the strace. -- Rob -- PHP General Mailing List (http://www.php.net/) To unsubscribe, visit: http://www.php.net/unsub.php
Re: [PHP] Re: Slow sessions.
On 3/26/2011 11:07 AM, Bostjan Skufca wrote: Can you strace it's execution and see where your delay is comming from? If you are using apache, make it create just one child and strace that one when you generate a request. Thanks for the advice. I installed strace on the new server, and it has a thirty second delay on the flock call (opening the session file): open(/path/to/session/sess_SESSIONID, O_RDWR|O_CREAT, 0600) = 20 flock(20, LOCK_EX) = -1 ENOLCK (No locks available) fcntl64(20, F_SETFD, FD_CLOEXEC)= 0 fstat64(20, {st_mode=S_IFREG|0644, st_size=13, ...}) = 0 pread64(20, cpixUser|b:1;, 13, 0) = 13 gettimeofday({1301331125, 622954}, NULL) = 0 gettimeofday({1301331125, 623046}, NULL) = 0 brk(0x989d000) = 0x989d000 gettimeofday({1301331125, 623301}, NULL) = 0 pwrite64(20, cpixUser|b:1;, 13, 0)= 13 close(20) = 0 This has the correct session file name (ie /path/to/session/sess_SESSIONID). So then I installed strace on one of the older servers, to see what it was doing, and this is what I see where it is opening the session file: open(\M\235\240GU\21, O_RDWR|O_CREAT, 0600) = 9 flock(9, LOCK_EX) = -1 EOPNOTSUPP (Operation not supported) fcntl(9, F_SETFD, FD_CLOEXEC) = 0 fstat(9, {st_mode=S_IFCHR|040, st_rdev=makedev(113, 1114152), ...}) = 0 lseek(9, 0, SEEK_SET) = 0 read(9, cpixUser|b:1;..., 13) = 13 gettimeofday({540876916, 1078020164}, {3221773391, 671636288}) = 0 sigprocmask(SIG_BLOCK, NULL, [])= 0 lseek(9, 0, SEEK_SET) = 0 write(9, cpixUser|b:1;..., 13)= 13 close(9)= 0 I don't know why it has the session file as this: \M\235\240GU\21. So it looks like the flock(?) is taking 30 seconds to timeout on the new server, and failing instantly on the old ones. On the new server, I have a message in /var/log/messages that reads: Mar 28 10:38:34 webServer kernel: lockd: server mainFileServer not responding, timed out I get this message evertime I call session_start(). I have tried reloading the new server from scratch (CentOS 5.5, php 5.2.17, apache 2.2) and it is still doing the same thing. -- PHP General Mailing List (http://www.php.net/) To unsubscribe, visit: http://www.php.net/unsub.php
Re: [PHP] Re: Slow sessions.
Bostjan, Thanks again for the tip. At this point, it looks like there is an issue with my main file server. It's weird that the older servers were working with it fine though (by instantly failing on lock), so I originally thought it might be a php issue. I think I'm making progress on it now though. -- Rob On 3/28/2011 12:08 PM, Rob Adams wrote: On 3/26/2011 11:07 AM, Bostjan Skufca wrote: Can you strace it's execution and see where your delay is comming from? If you are using apache, make it create just one child and strace that one when you generate a request. Thanks for the advice. I installed strace on the new server, and it has a thirty second delay on the flock call (opening the session file): open(/path/to/session/sess_SESSIONID, O_RDWR|O_CREAT, 0600) = 20 flock(20, LOCK_EX) = -1 ENOLCK (No locks available) fcntl64(20, F_SETFD, FD_CLOEXEC) = 0 fstat64(20, {st_mode=S_IFREG|0644, st_size=13, ...}) = 0 pread64(20, cpixUser|b:1;, 13, 0) = 13 gettimeofday({1301331125, 622954}, NULL) = 0 gettimeofday({1301331125, 623046}, NULL) = 0 brk(0x989d000) = 0x989d000 gettimeofday({1301331125, 623301}, NULL) = 0 pwrite64(20, cpixUser|b:1;, 13, 0) = 13 close(20) = 0 This has the correct session file name (ie /path/to/session/sess_SESSIONID). So then I installed strace on one of the older servers, to see what it was doing, and this is what I see where it is opening the session file: open(\M\235\240GU\21, O_RDWR|O_CREAT, 0600) = 9 flock(9, LOCK_EX) = -1 EOPNOTSUPP (Operation not supported) fcntl(9, F_SETFD, FD_CLOEXEC) = 0 fstat(9, {st_mode=S_IFCHR|040, st_rdev=makedev(113, 1114152), ...}) = 0 lseek(9, 0, SEEK_SET) = 0 read(9, cpixUser|b:1;..., 13) = 13 gettimeofday({540876916, 1078020164}, {3221773391, 671636288}) = 0 sigprocmask(SIG_BLOCK, NULL, []) = 0 lseek(9, 0, SEEK_SET) = 0 write(9, cpixUser|b:1;..., 13) = 13 close(9) = 0 I don't know why it has the session file as this: \M\235\240GU\21. So it looks like the flock(?) is taking 30 seconds to timeout on the new server, and failing instantly on the old ones. On the new server, I have a message in /var/log/messages that reads: Mar 28 10:38:34 webServer kernel: lockd: server mainFileServer not responding, timed out I get this message evertime I call session_start(). I have tried reloading the new server from scratch (CentOS 5.5, php 5.2.17, apache 2.2) and it is still doing the same thing. -- PHP General Mailing List (http://www.php.net/) To unsubscribe, visit: http://www.php.net/unsub.php
Re: [PHP] Re: Slow sessions.
Great, please report back if/when you discover the cause. Meanwhile doing man 2 flock yields info about ENOLCK: The kernel ran out of memory for allocating lock records. This concerns your new server. The old one does not support locking, or so it seems (EOPNOTSUPP). b. On 28 March 2011 23:15, Rob Adams rad...@circlepix.com wrote: Bostjan, Thanks again for the tip. At this point, it looks like there is an issue with my main file server. It's weird that the older servers were working with it fine though (by instantly failing on lock), so I originally thought it might be a php issue. I think I'm making progress on it now though. -- Rob On 3/28/2011 12:08 PM, Rob Adams wrote: On 3/26/2011 11:07 AM, Bostjan Skufca wrote: Can you strace it's execution and see where your delay is comming from? If you are using apache, make it create just one child and strace that one when you generate a request. Thanks for the advice. I installed strace on the new server, and it has a thirty second delay on the flock call (opening the session file): open(/path/to/session/sess_SESSIONID, O_RDWR|O_CREAT, 0600) = 20 flock(20, LOCK_EX) = -1 ENOLCK (No locks available) fcntl64(20, F_SETFD, FD_CLOEXEC) = 0 fstat64(20, {st_mode=S_IFREG|0644, st_size=13, ...}) = 0 pread64(20, cpixUser|b:1;, 13, 0) = 13 gettimeofday({1301331125, 622954}, NULL) = 0 gettimeofday({1301331125, 623046}, NULL) = 0 brk(0x989d000) = 0x989d000 gettimeofday({1301331125, 623301}, NULL) = 0 pwrite64(20, cpixUser|b:1;, 13, 0) = 13 close(20) = 0 This has the correct session file name (ie /path/to/session/sess_SESSIONID). So then I installed strace on one of the older servers, to see what it was doing, and this is what I see where it is opening the session file: open(\M\235\240GU\21, O_RDWR|O_CREAT, 0600) = 9 flock(9, LOCK_EX) = -1 EOPNOTSUPP (Operation not supported) fcntl(9, F_SETFD, FD_CLOEXEC) = 0 fstat(9, {st_mode=S_IFCHR|040, st_rdev=makedev(113, 1114152), ...}) = 0 lseek(9, 0, SEEK_SET) = 0 read(9, cpixUser|b:1;..., 13) = 13 gettimeofday({540876916, 1078020164}, {3221773391, 671636288}) = 0 sigprocmask(SIG_BLOCK, NULL, []) = 0 lseek(9, 0, SEEK_SET) = 0 write(9, cpixUser|b:1;..., 13) = 13 close(9) = 0 I don't know why it has the session file as this: \M\235\240GU\21. So it looks like the flock(?) is taking 30 seconds to timeout on the new server, and failing instantly on the old ones. On the new server, I have a message in /var/log/messages that reads: Mar 28 10:38:34 webServer kernel: lockd: server mainFileServer not responding, timed out I get this message evertime I call session_start(). I have tried reloading the new server from scratch (CentOS 5.5, php 5.2.17, apache 2.2) and it is still doing the same thing. -- PHP General Mailing List (http://www.php.net/) To unsubscribe, visit: http://www.php.net/unsub.php
Re: [PHP] Re: Slow sessions.
When you say you installed php 5.3.x and then reverted to 5.2, did you reinstall/upgrade OS and/or kernel too? b. On 28 March 2011 23:40, Bostjan Skufca bost...@a2o.si wrote: Great, please report back if/when you discover the cause. Meanwhile doing man 2 flock yields info about ENOLCK: The kernel ran out of memory for allocating lock records. This concerns your new server. The old one does not support locking, or so it seems (EOPNOTSUPP). b. On 28 March 2011 23:15, Rob Adams rad...@circlepix.com wrote: Bostjan, Thanks again for the tip. At this point, it looks like there is an issue with my main file server. It's weird that the older servers were working with it fine though (by instantly failing on lock), so I originally thought it might be a php issue. I think I'm making progress on it now though. -- Rob On 3/28/2011 12:08 PM, Rob Adams wrote: On 3/26/2011 11:07 AM, Bostjan Skufca wrote: Can you strace it's execution and see where your delay is comming from? If you are using apache, make it create just one child and strace that one when you generate a request. Thanks for the advice. I installed strace on the new server, and it has a thirty second delay on the flock call (opening the session file): open(/path/to/session/sess_SESSIONID, O_RDWR|O_CREAT, 0600) = 20 flock(20, LOCK_EX) = -1 ENOLCK (No locks available) fcntl64(20, F_SETFD, FD_CLOEXEC) = 0 fstat64(20, {st_mode=S_IFREG|0644, st_size=13, ...}) = 0 pread64(20, cpixUser|b:1;, 13, 0) = 13 gettimeofday({1301331125, 622954}, NULL) = 0 gettimeofday({1301331125, 623046}, NULL) = 0 brk(0x989d000) = 0x989d000 gettimeofday({1301331125, 623301}, NULL) = 0 pwrite64(20, cpixUser|b:1;, 13, 0) = 13 close(20) = 0 This has the correct session file name (ie /path/to/session/sess_SESSIONID). So then I installed strace on one of the older servers, to see what it was doing, and this is what I see where it is opening the session file: open(\M\235\240GU\21, O_RDWR|O_CREAT, 0600) = 9 flock(9, LOCK_EX) = -1 EOPNOTSUPP (Operation not supported) fcntl(9, F_SETFD, FD_CLOEXEC) = 0 fstat(9, {st_mode=S_IFCHR|040, st_rdev=makedev(113, 1114152), ...}) = 0 lseek(9, 0, SEEK_SET) = 0 read(9, cpixUser|b:1;..., 13) = 13 gettimeofday({540876916, 1078020164}, {3221773391, 671636288}) = 0 sigprocmask(SIG_BLOCK, NULL, []) = 0 lseek(9, 0, SEEK_SET) = 0 write(9, cpixUser|b:1;..., 13) = 13 close(9) = 0 I don't know why it has the session file as this: \M\235\240GU\21. So it looks like the flock(?) is taking 30 seconds to timeout on the new server, and failing instantly on the old ones. On the new server, I have a message in /var/log/messages that reads: Mar 28 10:38:34 webServer kernel: lockd: server mainFileServer not responding, timed out I get this message evertime I call session_start(). I have tried reloading the new server from scratch (CentOS 5.5, php 5.2.17, apache 2.2) and it is still doing the same thing. -- PHP General Mailing List (http://www.php.net/) To unsubscribe, visit: http://www.php.net/unsub.php
Re: [PHP] Re: Slow sessions.
From: Bostjan Skufca bost...@a2o.si When you say you installed php 5.3.x and then reverted to 5.2, did you reinstall/upgrade OS and/or kernel too? Yes. The old servers were running some version of FreeBSD. The new server is running CentOS 5.5. -- Rob -- PHP General Mailing List (http://www.php.net/) To unsubscribe, visit: http://www.php.net/unsub.php
Re: [PHP] Re: Slow sessions.
Seems like session file locking did not work before :) b. On 29 March 2011 01:00, Rob Adams rad...@circlepix.com wrote: From: Bostjan Skufca bost...@a2o.si When you say you installed php 5.3.x and then reverted to 5.2, did you reinstall/upgrade OS and/or kernel too? Yes. The old servers were running some version of FreeBSD. The new server is running CentOS 5.5. -- Rob
Re: [PHP] Re: Slow sessions.
Can you strace it's execution and see where your delay is comming from? If you are using apache, make it create just one child and strace that one when you generate a request. b. On 25 March 2011 19:01, Rob Adams rad...@circlepix.com wrote: I decided to try changing the session.save_path, and I've had some interesting results. First I changed it to a local directory. Originally it was on a mounted directory on our main file server. When I switched to a local directory, everything started working fast again on the php 5.2.17 server. So then I tried switching it to a different server mount. I set the session.save_path to a directory mounted on our backup file server. Once again, everything ran super fast. So then I tried switching it to a different mount on the main file server again. And it was back to taking at least 30 seconds to load. So, here's where I'm at: 4 other php 5.1.6 servers are using \\server1\mnt\phpsess as their session.save_path and are working just fine. My new installation of php 5.2.17 takes 30 seconds to start a session when mounting \\server1\mnt\phpsess. It also takes 30 seconds to start a session when mounting \\server1\mnt\testSess (a newly created dir). The php 5.2.17 server loads a session instantly when mounting \\server2\mnt\phpsess. I suppose I could just change the other four servers to use server2, and I might end up doing that, but it'd be like claiming defeat. I'd really like to figure out why this is happening. Any suggestions? Thanks. -- Rob -- PHP General Mailing List (http://www.php.net/) To unsubscribe, visit: http://www.php.net/unsub.php