[Ocfs2-users] OCFS2 and PHP is it related to ocfs2 ?

Sunil Mushran sunil.mushran at gmail.com
Fri May 2 14:12:41 PDT 2014


So these are all spinning to get the lock. You need to find the lock
holder. Dump the stack of all processes using the fs. Most of the stacks
should be similar to the one above. The useful ones will be the stacks that
is/are not similar to the above.


On Fri, May 2, 2014 at 8:48 AM, <molo.coc at web.de> wrote:

>  Thanks for your help! attached i execute the command for two PHP-FPM
> pids, which are in state 'r' = Running and consume 30% cpu time
>
> root at ispconfig:~# cat /proc/5236/stack
> [<ffffffffa0430aa2>] ocfs2_inode_cache_io_lock+0x12/0x20 [ocfs2]
> [<ffffffffa04790f9>] ocfs2_metadata_cache_io_lock+0x19/0x20 [ocfs2]
> [<ffffffffa04118a9>] ocfs2_read_blocks+0xe9/0x6d0 [ocfs2]
> [<ffffffffa0433deb>] ocfs2_read_inode_block_full+0x3b/0x60 [ocfs2]
> [<ffffffffa0434760>] ocfs2_read_inode_block+0x10/0x20 [ocfs2]
> [<ffffffffa0492edd>] ocfs2_iop_get_acl+0x3d/0x80 [ocfs2]
> [<ffffffff81735aaf>] check_acl+0xb9/0x133
> [<ffffffff811bf867>] generic_permission+0x107/0x120
> [<ffffffffa042aa5b>] ocfs2_permission+0x9b/0x100 [ocfs2]
> [<ffffffff811bf8f6>] __inode_permission+0x76/0xd0
> [<ffffffff811bf968>] inode_permission+0x18/0x50
> [<ffffffff811c188a>] link_path_walk+0x24a/0x8b0
> [<ffffffff811c3248>] path_lookupat+0x58/0x780
> [<ffffffff811c39a4>] filename_lookup+0x34/0xc0
> [<ffffffff811c4e99>] user_path_at_empty+0x59/0xa0
> [<ffffffff811c4ef1>] user_path_at+0x11/0x20
> [<ffffffff811b9e11>] vfs_fstatat+0x51/0xb0
> [<ffffffff811b9f3b>] vfs_stat+0x1b/0x20
> [<ffffffff811b9f55>] SYSC_newstat+0x15/0x30
> [<ffffffff811ba0ae>] SyS_newstat+0xe/0x10
> [<ffffffff817521dd>] system_call_fastpath+0x1a/0x1f
> [<ffffffffffffffff>] 0xffffffffffffffff
>
> Second PID
>  root at ispconfig:~# cat /proc/5329/stack
> [<ffffffff8109793a>] __cond_resched+0x2a/0x40
> [<ffffffffa0430aa2>] ocfs2_inode_cache_io_lock+0x12/0x20 [ocfs2]
> [<ffffffffa04790f9>] ocfs2_metadata_cache_io_lock+0x19/0x20 [ocfs2]
> [<ffffffffa04118a9>] ocfs2_read_blocks+0xe9/0x6d0 [ocfs2]
> [<ffffffffa0433deb>] ocfs2_read_inode_block_full+0x3b/0x60 [ocfs2]
> [<ffffffffa0434760>] ocfs2_read_inode_block+0x10/0x20 [ocfs2]
> [<ffffffffa0492edd>] ocfs2_iop_get_acl+0x3d/0x80 [ocfs2]
> [<ffffffff81735aaf>] check_acl+0xb9/0x133
> [<ffffffff811bf867>] generic_permission+0x107/0x120
> [<ffffffffa042aa5b>] ocfs2_permission+0x9b/0x100 [ocfs2]
> [<ffffffff811bf8f6>] __inode_permission+0x76/0xd0
> [<ffffffff811bf968>] inode_permission+0x18/0x50
> [<ffffffff811c188a>] link_path_walk+0x24a/0x8b0
> [<ffffffff811c1adc>] link_path_walk+0x49c/0x8b0
> [<ffffffff811c3248>] path_lookupat+0x58/0x780
> [<ffffffff811c39a4>] filename_lookup+0x34/0xc0
> [<ffffffff811c4e99>] user_path_at_empty+0x59/0xa0
> [<ffffffff811c4ef1>] user_path_at+0x11/0x20
> [<ffffffff811b30ac>] SyS_faccessat+0x9c/0x220
> [<ffffffff811b3248>] SyS_access+0x18/0x20
> [<ffffffff817521dd>] system_call_fastpath+0x1a/0x1f
> [<ffffffffffffffff>] 0xffffffffffffffff
>
>
> *Gesendet:* Freitag, 02. Mai 2014 um 17:16 Uhr
> *Von:* "Sunil Mushran" <sunil.mushran at gmail.com>
> *An:* molo.coc at web.de
> *Cc:* Ocfs2-users at oss.oracle.com
> *Betreff:* Re: Aw: Re: [Ocfs2-users] OCFS2 and PHP is it related to ocfs2
> ?
>
> Dump some kernel/user stacks to see if we can narrow down the loop it is
> spinning in.
>
> cat /process/PID/stack will show the kernel stack
> pstack should show user stack.
> On May 2, 2014 8:12 AM, <molo.coc at web.de> wrote:
>>
>>   its PHP-FPM
>>
>> root      1951  1.5  0.1 362344  7704 ?        Ss   17:09   0:01 php-fpm:
>> master process (/etc/php5/fpm/php-fpm.conf)
>> www-data  1953  0.0  0.1 360340  4868 ?        S    17:09   0:00
>> php-fpm: pool www
>> www-data  1954  0.0  0.1 360340  4868 ?        S    17:09   0:00
>> php-fpm: pool www
>> www-data  1955  0.0  0.1 360340  4868 ?        S    17:09   0:00
>> php-fpm: pool www
>> www-data  1956  0.0  0.1 360340  4868 ?        S    17:09   0:00
>> php-fpm: pool www
>> web1      2439 26.5  0.7 376132 30328 ?        R    17:10   0:17 php-fpm:
>> pool web1
>> web1      2442 18.3  0.6 375592 25524 ?        R    17:10   0:11 php-fpm:
>> pool web1
>> web1      2451 21.3  0.5 374200 21792 ?        R    17:10   0:08 php-fpm:
>> pool web1
>> web1      2453 27.0  0.3 366288 13960 ?        R    17:10   0:11 php-fpm:
>> pool web1
>> web1      2454 25.5  0.2 364068  9244 ?        R    17:10   0:10 php-fpm:
>> pool web1
>> web1      2455 31.6  0.2 364072  9716 ?        R    17:10   0:12 php-fpm:
>> pool web1
>> web1      2456 19.4  0.2 364312  9048 ?        R    17:10   0:07 php-fpm:
>> pool web1
>> web1      2458 22.9  0.2 364068  9108 ?        R    17:10   0:08 php-fpm:
>> pool web1
>> web1      2459 26.7  0.2 364068  9152 ?        R    17:10   0:10 php-fpm:
>> pool web1
>> web1      2460 19.3  0.2 364020  9136 ?        R    17:10   0:07 php-fpm:
>> pool web1
>> web1      2461 23.4  0.2 364068  9092 ?        R    17:10   0:09 php-fpm:
>> pool web1
>> web1      2462 19.6  0.2 364068  8948 ?        R    17:10   0:07 php-fpm:
>> pool web1
>> web1      2463 23.7  0.2 364072  8988 ?        R    17:10   0:09 php-fpm:
>> pool web1
>> web1      2466 27.2  0.2 364068  9072 ?        R    17:10   0:10 php-fpm:
>> pool web1
>> web1      2471 24.2  0.2 364040  9160 ?        R    17:10   0:08 php-fpm:
>> pool web1
>> web1      2472 20.7  0.2 364068  8948 ?        R    17:10   0:07 php-fpm:
>> pool web1
>> web1      2473 21.2  0.2 364068  8912 ?        R    17:10   0:07 php-fpm:
>> pool web1
>> web1      2482 19.8  0.2 364068  8924 ?        R    17:10   0:07 php-fpm:
>> pool web1
>> web1      2483 22.0  0.2 364068  8964 ?        R    17:10   0:07 php-fpm:
>> pool web1
>> web1      2484 22.4  0.2 364068  8984 ?        R    17:10   0:08 php-fpm:
>> pool web1
>> web1      2485 22.2  0.2 364068  8904 ?        R    17:10   0:07 php-fpm:
>> pool web1
>> web1      2486 16.5  0.2 364068  8852 ?        R    17:10   0:05 php-fpm:
>> pool web1
>> web1      2487 22.4  0.2 364076  8864 ?        R    17:10   0:07 php-fpm:
>> pool web1
>> web1      2488 24.3  0.2 364068  9020 ?        R    17:10   0:08 php-fpm:
>> pool web1
>> web1      2499 29.7  0.2 364068  9080 ?        R    17:10   0:10 php-fpm:
>> pool web1
>> web1      2500 19.8  0.2 364068  8996 ?        R    17:10   0:06 php-fpm:
>> pool web1
>> web1      2502 31.3  0.2 364068  9168 ?        R    17:10   0:10 php-fpm:
>> pool web1
>> web1      2503 20.9  0.2 364020  8984 ?        R    17:10   0:07 php-fpm:
>> pool web1
>>  root      2277  1.3  0.4 438232 16256 ?        Ss   17:09   0:01
>> /usr/sbin/apache2 -k start
>> www-data  2283  0.3  0.0 134164  3928 ?        S    17:09   0:00
>> /usr/sbin/apache2 -k start
>> www-data  2293  2.2  0.2 439204  9904 ?        S    17:09   0:02
>> /usr/sbin/apache2 -k start
>> www-data  2294  1.4  0.2 439572 10616 ?        S    17:09   0:01
>> /usr/sbin/apache2 -k start
>> www-data  2295  2.7  0.2 439288 10016 ?        S    17:09   0:02
>> /usr/sbin/apache2 -k start
>> www-data  2296  2.9  0.2 439632 10364 ?        S    17:09   0:03
>> /usr/sbin/apache2 -k start
>> www-data  2297  2.9  0.2 439204 10052 ?        S    17:09   0:03
>> /usr/sbin/apache2 -k start
>> www-data  2440  3.5  0.2 439196 10016 ?        S    17:10   0:03
>> /usr/sbin/apache2 -k start
>> www-data  2443  1.5  0.2 439300 10160 ?        S    17:10   0:01
>> /usr/sbin/apache2 -k start
>> www-data  2444  0.2  0.2 439188  9908 ?        S    17:10   0:00
>> /usr/sbin/apache2 -k start
>> www-data  2445  0.5  0.2 439188  9908 ?        S    17:10   0:00
>> /usr/sbin/apache2 -k start
>> www-data  2446  0.4  0.2 439188  9908 ?        S    17:10   0:00
>> /usr/sbin/apache2 -k start
>> www-data  2447  0.4  0.2 439188  9908 ?        S    17:10   0:00
>> /usr/sbin/apache2 -k start
>> www-data  2448  0.4  0.2 439188  9908 ?        S    17:10   0:00
>> /usr/sbin/apache2 -k start
>> www-data  2449  0.3  0.2 439188  9908 ?        S    17:10   0:00
>> /usr/sbin/apache2 -k start
>> www-data  2450  0.5  0.2 439188  9908 ?        S    17:10   0:00
>> /usr/sbin/apache2 -k start
>> www-data  2457  0.9  0.2 439188  9908 ?        S    17:10   0:00
>> /usr/sbin/apache2 -k start
>> www-data  2464  0.2  0.2 439188  9908 ?        S    17:10   0:00
>> /usr/sbin/apache2 -k start
>> www-data  2465  0.3  0.2 439188  9908 ?        S    17:10   0:00
>> /usr/sbin/apache2 -k start
>> www-data  2467  0.5  0.2 439188  9908 ?        S    17:10   0:00
>> /usr/sbin/apache2 -k start
>> www-data  2468  0.4  0.2 439188  9908 ?        S    17:10   0:00
>> /usr/sbin/apache2 -k start
>> www-data  2469  0.5  0.2 439188  9908 ?        S    17:10   0:00
>> /usr/sbin/apache2 -k start
>> www-data  2470  0.4  0.2 439188  9908 ?        S    17:10   0:00
>> /usr/sbin/apache2 -k start
>> www-data  2474  0.1  0.2 439188  9908 ?        S    17:10   0:00
>> /usr/sbin/apache2 -k start
>> www-data  2475  0.3  0.2 439188  9908 ?        S    17:10   0:00
>> /usr/sbin/apache2 -k start
>> www-data  2476  0.4  0.2 439188  9908 ?        S    17:10   0:00
>> /usr/sbin/apache2 -k start
>> www-data  2477  0.4  0.2 439188  9908 ?        S    17:10   0:00
>> /usr/sbin/apache2 -k start
>> www-data  2478  0.3  0.2 439188  9908 ?        S    17:10   0:00
>> /usr/sbin/apache2 -k start
>> www-data  2479  0.3  0.2 439188  9908 ?        S    17:10   0:00
>> /usr/sbin/apache2 -k start
>> www-data  2480  0.2  0.2 439188  9908 ?        S    17:10   0:00
>> /usr/sbin/apache2 -k start
>> www-data  2481  0.2  0.2 439188  9908 ?        S    17:10   0:00
>> /usr/sbin/apache2 -k start
>> www-data  2489  0.2  0.2 439188  9908 ?        S    17:10   0:00
>> /usr/sbin/apache2 -k start
>> www-data  2490  0.1  0.2 439188  9908 ?        S    17:10   0:00
>> /usr/sbin/apache2 -k start
>> www-data  2491  0.4  0.2 439188  9908 ?        S    17:10   0:00
>> /usr/sbin/apache2 -k start
>> www-data  2492  0.1  0.2 439188  9908 ?        S    17:10   0:00
>> /usr/sbin/apache2 -k start
>> www-data  2493  3.1  0.2 439132  9908 ?        S    17:10   0:01
>> /usr/sbin/apache2 -k start
>> www-data  2494  0.1  0.2 439188  9908 ?        S    17:10   0:00
>> /usr/sbin/apache2 -k start
>> www-data  2495  0.2  0.2 439188  9908 ?        S    17:10   0:00
>> /usr/sbin/apache2 -k start
>> www-data  2496  1.5  0.2 439132  9908 ?        S    17:10   0:00
>> /usr/sbin/apache2 -k start
>> www-data  2498  1.6  0.2 439132  9908 ?        S    17:10   0:01
>> /usr/sbin/apache2 -k start
>> www-data  2501  0.8  0.2 439132  9908 ?        S    17:10   0:00
>> /usr/sbin/apache2 -k start
>> www-data  2505  0.6  0.2 439132  9908 ?        S    17:10   0:00
>> /usr/sbin/apache2 -k start
>> www-data  2506  0.7  0.2 439132  9908 ?        S    17:10   0:00
>> /usr/sbin/apache2 -k start
>> www-data  2507  0.6  0.2 439132  9908 ?        S    17:10   0:00
>> /usr/sbin/apache2 -k start
>> www-data  2508  0.8  0.2 439132  9908 ?        S    17:10   0:00
>> /usr/sbin/apache2 -k start
>>
>>  Which process is pegging the CPU?
>>   On May 2, 2014 6:12 AM, <molo.coc at web.de> wrote:
>>>
>>>  We have two nodes which are serving PHP webpages with PHP5-FPM. Both
>>> Nodes are configured with drbd in dual primary mode.
>>> In our tests, if one of these two nodes get 10-20 Pagerefresh's at the
>>> same time,  the CPU are 100% in use.
>>> For these 10-20 Pagerequests the server are 1.5 minutes busy.
>>>
>>> Without OCFS (harddrive is formatted with ext4)  for the same 10-20
>>> requests, it tooks only 0.1 Seconds to complete.
>>> We only see a long running PHP Process which get timeouted sometime with
>>> '30 seconds exceeded for including a file' . We tried mounting the ocfs2
>>> device with 'noatime, nodiratime, data=writeback', but it didn't helped.
>>>
>>> does someone has a tip for us ?
>>> (If we use ocfs2 with icsci, there are no changes)
>>>
>>> thanks a lot!
>>>
>>> _______________________________________________
>>> Ocfs2-users mailing list
>>> Ocfs2-users at oss.oracle.com
>>> https://oss.oracle.com/mailman/listinfo/ocfs2-users
>>
>>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://oss.oracle.com/pipermail/ocfs2-users/attachments/20140502/2764fddb/attachment-0001.html 


More information about the Ocfs2-users mailing list