In other news, there's a blog entry (finally) on the GridPP Storage
blog about what we did at Glasgow to reduce load. (xrootd direct IO
and slowing the rate of analysis job starts).
Sam
On 24 October 2013 08:10, Wahid Bhimji <[log in to unmask]> wrote:
> Hi
>
> Sorry you are still having loading issues. A few thoughts:
>
> 1. Do you have the tuning applied on this disk servers from this page -
> specifically the block device readahead
> https://www.gridpp.ac.uk/wiki/Performance_and_Tuning#Tuning_block_device_readahead
>
> 2. I would move to xrootd instead of rfio for atlas jobs - at least we can
> then, if it still happens, ask the DPM core team - otherwise they will just
> suggest it. If you have xrootd running on all the machines it is a simple
> switch in agis.
>
> 3. Do others see this number of globus-gridftp-server processes? I looked
> on my disk servers and I currently only see one on each that has been
> running since over a month… this may be a sign of something strange or a
> symptom or it may be just me. Also mine doesn't have the -inetd option - but
> this might be all a red herrings:
> /usr/sbin/globus-gridftp-server -d all -p 2811 -auth-level 0 -dsi dpm
> -disable-usage-stats -l /var/log/dpm-gsiftp/gridftp.log -Z
> /var/log/dpm-gsiftp/dpm-gsiftp.log -no-detach -config-base-path /
>
> 4. Unbalanced datasets - maybe sam can help you there - at least to see if
> there are such datasets even if not to redistribute them
>
> Wahid
>
> On 24 Oct 2013, at 00:42, Elena Korolkova <[log in to unmask]>
> wrote:
>
> Hi
>
> close look at an overloaded disk server shows 130 globus-gridftp-server
> processes
>
> log/dpm-gsiftp/gridftp.log -Z /var/log/dpm-gsiftp/dpm-gsiftp.log -no-detach
> -config-base-path / -inetd -config-base-path /
> prdatl88 32448 0.8 0.0 118768 6936 ? D 17:15 0:29
> /usr/sbin/globus-gridftp-server -d all -p 2811 -auth-level 0 -dsi dpm
> -disable-usage-stats -l /var/log/dpm-gsiftp/gridftp.log -Z
> /var/log/dpm-gsiftp/dpm-gsiftp.log -no-detach -config-base-path / -inetd
> -config-base-path /
> prdatl88 32467 0.7 0.0 118052 6196 ? D 17:16 0:24
> /usr/sbin/globus-gridftp-server -d all -p 2811 -auth-level 0 -dsi dpm
> -disable-usage-stats -l /var/log/dpm-gsiftp/gridftp.log -Z
> /var/log/dpm-gsiftp/dpm-gsiftp.log -no-detach -config-base-path / -inetd
> -config-base-path /
> prdatl88 32488 0.8 0.0 118768 6932 ? D 17:17 0:28
> /usr/sbin/globus-gridftp-server -d all -p 2811 -auth-level 0 -dsi dpm
> -disable-usage-stats -l /var/log/dpm-gsiftp/gridftp.log -Z
> /var/log/dpm-gsiftp/dpm-gsiftp.log -no-detach -config-base-path / -inetd
> -config-base-path /
> prdatl88 32505 0.8 0.0 118768 6928 ? D 17:18 0:25
> /usr/sbin/globus-gridftp-server -d all -p 2811 -auth-level 0 -dsi dpm
> -disable-usage-stats -l /var/log/dpm-gsiftp/gridftp.log -Z
> /var/log/dpm-gsiftp/dpm-gsiftp.log -no-detach -config-base-path / -inetd
> -config-base-path /
> prdatl88 32530 0.6 0.0 118768 6932 ? D 17:19 0:19
> /usr/sbin/globus-gridftp-server -d all -p 2811 -auth-level 0 -dsi dpm
> -disable-usage-stats -l /var/log/dpm-gsiftp/gridftp.log -Z
> /var/log/dpm-gsiftp/dpm-gsiftp.log -no-detach -config-base-path / -inetd
> -config-base-path /
> prdatl88 32574 1.3 0.0 122920 11100 ? S 17:21 0:40
> /usr/sbin/globus-gridftp-server -d all -p 2811 -auth-level 0 -dsi dpm
> -disable-usage-stats -l /var/log/dpm-gsiftp/gridftp.log -Z
> /var/log/dpm-gsiftp/dpm-gsiftp.log -no-detach -config-base-path / -inetd
> -config-base-path /
> prdatl88 32575 0.7 0.0 118768 6928 ? D 17:21 0:22
> /usr/sbin/globus-gridftp-server -d all -p 2811 -auth-level 0 -dsi dpm
> -disable-usage-stats -l /var/log/dpm-gsiftp/gridftp.log -Z
> /var/log/dpm-gsiftp/dpm-gsiftp.log -no-detach -config-base-path / -inetd
> -config-base-path /
> prdatl88 32591 0.7 0.0 118052 6192 ? S 17:22 0:22
> /usr/sbin/globus-gridftp-server -d all -p 2811 -auth-level 0 -dsi dpm
> -disable-usage-stats -l /var/log/dpm-gsiftp/gridftp.log -Z
> /var/log/dpm-gsiftp/dpm-gsiftp.log -no-detach -config-base-path / -inetd
> -config-base-path /
> prdatl88 32598 1.0 0.0 121900 8132 ? D 17:23 0:30
> /usr/sbin/globus-gridftp-server -d all -p 2811 -auth-level 0 -dsi dpm
> -disable-usage-stats -l /var/log/dpm-gsiftp/gridftp.log -Z
> /var/log/dpm-gsiftp/dpm-gsiftp.log -no-detach -config-base-path / -inetd
> -config-base-path /
> prdatl88 32632 0.6 0.0 118768 6936 ? D 17:25 0:17
> /usr/sbin/globus-gridftp-server -d all -p 2811 -auth-level 0 -dsi dpm
> -disable-usage-stats -l /var/log/dpm-gsiftp/gridftp.log -Z
> /var/log/dpm-gsiftp/dpm-gsiftp.log -no-detach -config-base-path / -inetd
> -config-base-path /
> prdatl88 32701 1.2 0.0 122936 8696 ? S 17:28 0:31
> /usr/sbin/globus-gridftp-server -d all -p 2811 -auth-level 0 -dsi dpm
> -disable-usage-stats -l /var/log/dpm-gsiftp/gridftp.log -Z
> /var/log/dpm-gsiftp/dpm-gsiftp.log -no-detach -config-base-path / -inetd
> -config-base-path /
> prdatl88 32713 1.6 0.0 122936 11136 ? S 17:29 0:40
> /usr/sbin/globus-gridftp-server -d all -p 2811 -auth-level 0 -dsi dpm
> -disable-usage-stats -l /var/log/dpm-gsiftp/gridftp.log -Z
> /var/log/dpm-gsiftp/dpm-gsiftp.log -no-detach -config-base-path / -inetd
> -config-base-path /
> prdatl88 32717 0.6 0.0 118768 6928 ? D 17:30 0:17
> /usr/sbin/globus-gridftp-server -d all -p 2811 -auth-level 0 -dsi dpm
> -disable-usage-stats -l /var/log/dpm-gsiftp/gridftp.log -Z
> /var/log/dpm-gsiftp/dpm-gsiftp.log -no-detach -config-base-path / -inetd
> -config-base-path /
> prdatl88 32740 0.7 0.0 118768 6932 ? D 17:31 0:18
> /usr/sbin/globus-gridftp-server -d all -p 2811 -auth-level 0 -dsi dpm
> -disable-usage-stats -l /var/log/dpm-gsiftp/gridftp.log -Z
> /var/log/dpm-gsiftp/dpm-gsiftp.log -no-detach -config-base-path / -inetd
> -config-base-path /
> prdatl88 32763 0.6 0.0 118768 6932 ? D 17:32 0:14
> /usr/sbin/globus-gridftp-server -d all -p 2811 -auth-level 0 -dsi dpm
> -disable-usage-stats -l /var/log/dpm-gsiftp/gridftp.log -Z
> /var/log/dpm-gsiftp/dpm-gsiftp.log -no-detach -config-base-path / -inetd
> -config-base-path /
>
>
>
> In /var/log/rfio/log I see error messages like this:
>
> Oct 23 21:17:59 rfiod[7854]: Waiting for end of child 10737, status 1
> Oct 23 21:17:59 rfiod[10738]: doit(5): connection from [143.167.3.102]
> (lcgse0.shef.ac.uk)
> Oct 23 21:17:59 rfiod[10739]: doit(5): connection from [143.167.3.102]
> (lcgse0.shef.ac.uk)
> Oct 23 21:17:59 rfiod[10741]: doit(5): connection from [192.168.42.130]
> (wn030.hep)
> Oct 23 21:17:59 rfiod[10740]: doit(5): connection from [143.167.3.102]
> (lcgse0.shef.ac.uk)
> Oct 23 21:17:59 rfiod[10739]: Could not establish an authenticated
> connection: server_establish_context_ext: Could not receive token;
> _Csec_recv_token: Connection closed; Csec_server_set_service_name: Could not
> set service name; Csec_get_peer_service_name: Could not Cgetnetaddress: BAD
> ERROR NUMBER: 0 !
> Oct 23 21:17:59 rfiod[10742]: doit(5): connection from [143.167.3.102]
> (lcgse0.shef.ac.uk)
> Oct 23 21:17:59 rfiod[10740]: Could not establish an authenticated
> connection: server_establish_context_ext: Could not receive token;
> _Csec_recv_token: Connection closed; Csec_server_set_service_name: Could not
> set service name; Csec_get_peer_service_name: Could not Cgetnetaddress: BAD
> ERROR NUMBER: 0 !
> Oct 23 21:17:59 rfiod[10742]: Could not establish an authenticated
> connection: server_establish_context_ext: Could not receive token;
> _Csec_recv_token: Connection closed; Csec_server_set_service_name: Could not
> set service name; Csec_get_peer_service_name: Could not Cgetnetaddress: BAD
> ERROR NUMBER: 0 !
>
> ice_name: Could not set service name; Csec_get_peer_service_name: Could not
> Cgetnetaddress: BAD ERROR NUMBER: 0 !
> Oct 23 21:17:59 rfiod[10741]: Could not establish an authenticated
> connection: _Csec_recv_token: Connection closed;
> Csec_server_set_service_name: Could not set service name;
> Csec_get_peer_service_name: Could not Cgetnetaddress: BAD ERROR NUMBER: 0 !
>
>
> /var/log/dpm-gsiftp/gridftp.log :
>
> 11177] Wed Oct 23 21:47:49 2013 :: GFork functionality not enabled.:
> [11177] Wed Oct 23 21:47:49 2013 :: Configuration read from
> /etc/gridftp.conf.
> [11177] Wed Oct 23 21:47:49 2013 :: Server started in inetd mode.
> [11177] Wed Oct 23 21:47:49 2013 :: New connection from:
> lcgfts08.gridpp.rl.ac.uk:51809
> [11177] Wed Oct 23 21:47:49 2013 :: lcgfts08.gridpp.rl.ac.uk:51809:
> [CLIENT]: USER :globus-mapping:
> [11177] Wed Oct 23 21:47:49 2013 :: lcgfts08.gridpp.rl.ac.uk:51809:
> [SERVER]: 331 Password required for :globus-mapping:.
> [11177] Wed Oct 23 21:47:49 2013 :: lcgfts08.gridpp.rl.ac.uk:51809:
> [CLIENT]: PASS
> [11177] Wed Oct 23 21:47:49 2013 :: request by /DC=ch/DC=cern/OU=Organic
> Units/OU=Users/CN=ddmadmin/CN=531497/CN=Robot: ATLAS Data Management from
> lcgfts08.gridpp.rl.ac.uk
> [11177] Wed Oct 23 21:47:50 2013 :: DN /DC=ch/DC=cern/OU=Organic
> Units/OU=Users/CN=ddmadmin/CN=531497/CN=Robot: ATLAS Data Management
> successfully authorized.
> [11177] Wed Oct 23 21:47:50 2013 :: User prdatl88 successfully authorized.
> [11177] Wed Oct 23 21:47:50 2013 :: lcgfts08.gridpp.rl.ac.uk:51809:
> [CLIENT]: PASS
> [11177] Wed Oct 23 21:47:50 2013 :: lcgfts08.gridpp.rl.ac.uk:51809:
> [SERVER]: 230 User prdatl88 logged in.
> [11177] Wed Oct 23 21:47:50 2013 :: lcgfts08.gridpp.rl.ac.uk:51809:
> [CLIENT]: SITE HELP
> [11177] Wed Oct 23 21:47:50 2013 :: lcgfts08.gridpp.rl.ac.uk:51809:
> [SERVER]: 214-The following commands are recognized:
> [11177] Wed Oct 23 21:47:50 2013 :: lcgfts08.gridpp.rl.ac.uk:51809:
> [CLIENT]: FEAT
> [11177] Wed Oct 23 21:47:50 2013 :: lcgfts08.gridpp.rl.ac.uk:51809:
> [SERVER]: 211-Extensions supported
> [11177] Wed Oct 23 21:47:50 2013 :: lcgfts08.gridpp.rl.ac.uk:51809:
> [CLIENT]: SITE CLIENTINFO
> scheme=gsiftp;appname="libglobus_ftp_client";appver="7.4 (gcc64,
> 1340810069-83) [Globus Toolkit 5.2.1]";
> [11177] Wed Oct 23 21:47:50 2013 :: lcgfts08.gridpp.rl.ac.uk:51809:
> [SERVER]: 250 OK.
> [11177] Wed Oct 23 21:47:50 2013 :: lcgfts08.gridpp.rl.ac.uk:51809:
> [CLIENT]: TYPE I
> [11177] Wed Oct 23 21:47:50 2013 :: lcgfts08.gridpp.rl.ac.uk:51809:
> [SERVER]: 200 Type set to I.
> [11177] Wed Oct 23 21:47:50 2013 :: lcgfts08.gridpp.rl.ac.uk:51809:
> [CLIENT]: PBSZ 1048576
> [11177] Wed Oct 23 21:47:50 2013 :: lcgfts08.gridpp.rl.ac.uk:51809:
> [SERVER]: 200 PBSZ=1048576
> [11177] Wed Oct 23 21:47:50 2013 :: lcgfts08.gridpp.rl.ac.uk:51809:
> [CLIENT]: DELE
> /lcgse9.shef.ac.uk:/storage1/atlas/2013-10-23/AOD.01328071._004259.pool.root.1.63161335.0
> [11177] Wed Oct 23 21:47:50 2013 :: lcgfts08.gridpp.rl.ac.uk:51809:
> [SERVER]: 500 Command failed : unlink error: Permission denied
> [11177] Wed Oct 23 21:47:50 2013 :: lcgfts08.gridpp.rl.ac.uk:51809:
> [CLIENT]: QUIT
> [11177] Wed Oct 23 21:47:50 2013 :: lcgfts08.gridpp.rl.ac.uk:51809:
> [SERVER]: 221 Goodbye.
> [11177] Wed Oct 23 21:47:50 2013 :: Closed connection from
> lcgfts08.gridpp.rl.ac.uk:51809
> [7891] Wed Oct 23 21:47:50 2013 :: Child process 11177 ended with rc = 0
>
> [10443] Wed Oct 23 22:11:00 2013 :: Failure attempting to transfer
> "/lcgse9.shef.ac.uk:/storage1/atlas/2013-10-23/EVNT.01361822._000004.pool.root.1.63152845.0".
> [10443] Wed Oct 23 22:11:00 2013 :: Transfer failure:
> [10443] Wed Oct 23 22:11:00 2013 :: force_close:
> [10443] Wed Oct 23 22:11:00 2013 :: lcgfta02.gridpp.rl.ac.uk:57242:
> [SERVER]: 500-Command failed. : globus_xio: System error in send: Broken
> pipe
> [10443] Wed Oct 23 22:11:00 2013 :: Closed connection from
> lcgfta02.gridpp.rl.ac.uk:57242
> [7891] Wed Oct 23 22:11:00 2013 :: Child process 10443 ended with rc = 0
>
>
> It looks like "Permission denied" errors are seen when disk servers are
> overloaded:
> [root@lcgse0 ~]# for i in `seq 10`; do ssh -tx root@se`printf %01d $i`
> 'grep "Permission denied" /var/log/dpm-gsiftp/gridftp.log|wc -l';done
> 29
> Connection to se1 closed.
> 26
> Connection to se2 closed.
> 0
> Connection to se3 closed.
> 0
> Connection to se4 closed.
> 108
> Connection to se5 closed.
> 129
> Connection to se6 closed.
> 62
> Connection to se7 closed.
> 56
> Connection to se8 closed.
> 87
> Connection to se9 closed.
> 11
> Connection to se10 closed.
>
>
> Any help/ideas are greatly appreciated.
>
> Elena
>
>
>
> __________________________________________________
> Dr Elena Korolkova
> Email: [log in to unmask]
> Tel.: +44 (0)114 2223553
> Fax: +44 (0)114 2223555
> Department of Physics and Astronomy
> University of Sheffield
> Sheffield, S3 7RH, United Kingdom
>
>
>
> The University of Edinburgh is a charitable body, registered in
> Scotland, with registration number SC005336.
>
|
