[
https://issues.apache.org/jira/browse/HADOOP-13871?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15733129#comment-15733129
]
Steve Loughran edited comment on HADOOP-13871 at 12/9/16 11:51 AM:
-------------------------------------------------------------------
Also now seen on trunk. netstat shows the link is up,
{code}
tcp4 0 0 192.168.1.12.55256 s3-us-west-2-r-w.https ESTABLISHED
{code}
and nettop shows inaction, though the rx_ooo counter seemed be incrementing at2
2KB/s for a bit, before hanging completely
{code}
state
packets_in bytes_in packets_out bytes_out rx_dupe rx_ooo re-tx rtt_avg
rtt_var rcvsize tx_win P C R W
java.16828
24502 13 MiB 8 3507 B 37 KiB 4654 KiB 0 B
tcp4 192.168.1.12:55256<->s3-us-west-2-r-w.amazonaws.com:443 Established
24502 13 MiB 8 3507 B 37 KiB 4654 KiB 0 B 185.31 ms
15.03 ms 256 KiB 21 KiB - - - -
{code}
That's 4MB of OOO packets for 13 MB read, symptomatic of routing fun.
Then, suddenly, that TCP connection got closed (socket timeout) and a new one
opened that went through the full dataset in a second or two
{code}
state packets_in bytes_in packets_out
bytes_out rx_dupe rx_ooo re-tx rtt_avg rtt_var rcvsize tx_win
P C R W
java.16828
41636 37 MiB 25
9210 B 37 KiB 4654 KiB 0 B
tcp4 192.168.1.12:55256<->s3-us-west-2-r-w.amazonaws.com:443
FinWait2 24502 13 MiB 9
3560 B 37 KiB 4654 KiB 0 B 184.16 ms 12.44 ms 256 KiB 21 KiB
- - - -
{code}
The really good news: curl is now suffering too. Which means its not a Java
problem. Either the latop (which has been rebooted with SMC reset), or the rest
of the network.
{code}
$ curl -O https://landsat-pds.s3.amazonaws.com/scene_list.gz
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
5 37.4M 5 2090k 0 0 11824 0 0:55:21 0:03:01 0:52:20 7039
$ nettop -p 17105
state packets_in bytes_in packets_out
bytes_out rx_dupe rx_ooo re-tx rtt_avg rtt_var rcvsize tx_win
P C R W
curl.17105
3178 2323 KiB 4
482 B 10232 B 918 KiB 0 B
tcp4 192.168.1.12:55731<->s3-us-west-2-w.amazonaws.com:443
Established 3178 2323 KiB 4
482 B 10232 B 918 KiB 0 B 173.56 ms 20.41 ms 256 KiB 16 KiB -
- - -
{code}
And on another attempt
{code}
curl -O https://landsat-pds.s3.amazonaws.com/scene_list.gz
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
100 37.4M 100 37.4M 0 0 4410k 0 0:00:08 0:00:08 --:--:-- 6382k
{code}
Conclusions
# sometimes over a network, we can get awful S3 read performance
# which goes away on a reconnect, including those detected by socket timeouts
# and which can be seen on other processes, so it's not a JVM/SDK problem
# which means that curl can be used as a probe independent of everything else;
nettop giving more details
I'm going to try to set some more aggressive socket timeouts than 200 seconds.
If it does address this, maybe we should consider having a smaller default.
Also: time for that advanced troubleshooting document
was (Author: ste...@apache.org):
Also now seen on trunk. netstat shows the link is up,
{code}
tcp4 0 0 192.168.1.12.55256 s3-us-west-2-r-w.https ESTABLISHED
{code}
and nettop shows inaction, though the rx_ooo counter seemed be incrementing at2
2KB/s for a bit, before hanging completely
{code}
state packets_in bytes_in packets_out
bytes_out rx_dupe rx_ooo re-tx rtt_avg rtt_var rcvsize tx_win
P C R W
java.16828
24502 13 MiB 8
3507 B 37 KiB 4654 KiB 0 B
tcp4 192.168.1.12:55256<->s3-us-west-2-r-w.amazonaws.com:443
Established 24502 13 MiB 8
3507 B 37 KiB 4654 KiB 0 B 185.31 ms 15.03 ms 256 KiB 21 KiB
- - - -
{code}
That's 4MB of OOO packets for 13 MB read, symptomatic of routing fun.
Then, suddenly, that TCP connection got closed (socket timeout) and a new one
opened that went through the full dataset in a second or two
{code}
state packets_in bytes_in packets_out
bytes_out rx_dupe rx_ooo re-tx rtt_avg rtt_var rcvsize tx_win
P C R W
java.16828
41636 37 MiB 25
9210 B 37 KiB 4654 KiB 0 B
tcp4 192.168.1.12:55256<->s3-us-west-2-r-w.amazonaws.com:443
FinWait2 24502 13 MiB 9
3560 B 37 KiB 4654 KiB 0 B 184.16 ms 12.44 ms 256 KiB 21 KiB
- - - -
{code}
The really good news: curl is now suffering too. Which means its not a Java
problem. Either the latop (which has been rebooted with SMC reset), or the rest
of the network.
{code}
$ curl -O https://landsat-pds.s3.amazonaws.com/scene_list.gz
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
5 37.4M 5 2090k 0 0 11824 0 0:55:21 0:03:01 0:52:20 7039
$ nettop -p 17105
state packets_in bytes_in packets_out
bytes_out rx_dupe rx_ooo re-tx rtt_avg rtt_var rcvsize tx_win
P C R W
curl.17105
3178 2323 KiB 4
482 B 10232 B 918 KiB 0 B
tcp4 192.168.1.12:55731<->s3-us-west-2-w.amazonaws.com:443
Established 3178 2323 KiB 4
482 B 10232 B 918 KiB 0 B 173.56 ms 20.41 ms 256 KiB 16 KiB -
- - -
{code}
And on another attempt
{code}
curl -O https://landsat-pds.s3.amazonaws.com/scene_list.gz
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
100 37.4M 100 37.4M 0 0 4410k 0 0:00:08 0:00:08 --:--:-- 6382k
{code}
Conclusions
# sometimes over a network, we can get awful S3 read performance
# which goes away on a reconnect, including those detected by socket timeouts
# and which can be seen on other processes, so it's not a JVM/SDK problem
# which means that curl can be used as a probe independent of everything else;
nettop giving more details
I'm going to try to set some more aggressive socket timeouts than 200 seconds.
If it does address this, maybe we should consider having a smaller default.
Also: time for that advanced troubleshooting document
> ITestS3AInputStreamPerformance.testTimeToOpenAndReadWholeFileBlocks
> performance on branch-2.8 awful
> ---------------------------------------------------------------------------------------------------
>
> Key: HADOOP-13871
> URL: https://issues.apache.org/jira/browse/HADOOP-13871
> Project: Hadoop Common
> Issue Type: Sub-task
> Components: fs/s3
> Affects Versions: 2.8.0, 2.9.0, 3.0.0-alpha2
> Environment: landsat bucket from the UK
> Reporter: Steve Loughran
> Assignee: Steve Loughran
> Attachments: HADOOP-13871-001.patch, HADOOP-13871-002.patch,
> org.apache.hadoop.fs.s3a.scale.ITestS3AInputStreamPerformance-output.txt
>
>
> The ITestS3AInputStreamPerformance.testTimeToOpenAndReadWholeFileBlocks takes
> 15s on branch-2, but is now taking minutes.
> This is a regression, and it's surfacing on some internal branches too. Even
> where the code hasn't changed. -It does not happen on branch-2, which has a
> later SDK.-
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
---------------------------------------------------------------------
To unsubscribe, e-mail: common-issues-unsubscr...@hadoop.apache.org
For additional commands, e-mail: common-issues-h...@hadoop.apache.org
