[
https://issues.apache.org/jira/browse/WAGON-545?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16750362#comment-16750362
]
Michael Osipov commented on WAGON-545:
--------------------------------------
Had a look, here is an example failure with
* connection initiation (first use)
* connection terminatoin (last use)
* failure
{noformat}
2019-01-23T14:33:22.2137612Z
[BasicRepositoryConnector-repo.maven.apache.org-2-2] [DEBUG] Connection
established 10.1.0.4:1927<->151.101.16.215:443
2019-01-23T14:33:22.2139422Z
[BasicRepositoryConnector-repo.maven.apache.org-2-2] [DEBUG] http-outgoing-273:
set socket timeout to 1800000
2019-01-23T14:33:22.2140062Z
[BasicRepositoryConnector-repo.maven.apache.org-2-2] [DEBUG] Executing request
GET /maven2/org/apache/maven/maven-model/3.0/maven-model-3.0.jar HTTP/1.1
2019-01-23T14:33:22.2142161Z
[BasicRepositoryConnector-repo.maven.apache.org-2-2] [DEBUG] Target auth state:
UNCHALLENGED
2019-01-23T14:33:22.2144596Z
[BasicRepositoryConnector-repo.maven.apache.org-2-2] [DEBUG] Proxy auth state:
UNCHALLENGED
2019-01-23T14:33:22.2148747Z
[BasicRepositoryConnector-repo.maven.apache.org-2-2] [DEBUG] http-outgoing-273
>> GET /maven2/org/apache/maven/maven-model/3.0/maven-model-3.0.jar HTTP/1.1
2019-01-23T14:33:22.2153319Z
[BasicRepositoryConnector-repo.maven.apache.org-2-2] [DEBUG] http-outgoing-273
>> Cache-control: no-cache
2019-01-23T14:33:22.2155384Z
[BasicRepositoryConnector-repo.maven.apache.org-2-2] [DEBUG] http-outgoing-273
>> Cache-store: no-store
2019-01-23T14:33:22.2155639Z
[BasicRepositoryConnector-repo.maven.apache.org-2-2] [DEBUG] http-outgoing-273
>> Pragma: no-cache
2019-01-23T14:33:22.2155950Z
[BasicRepositoryConnector-repo.maven.apache.org-2-2] [DEBUG] http-outgoing-273
>> User-Agent: Apache-Maven/3.6.0 (Java 1.8.0_181; Windows Server 2016 10.0)
2019-01-23T14:33:22.2156614Z
[BasicRepositoryConnector-repo.maven.apache.org-2-2] [DEBUG] http-outgoing-273
>> Host: repo.maven.apache.org
2019-01-23T14:33:22.2156794Z
[BasicRepositoryConnector-repo.maven.apache.org-2-2] [DEBUG] http-outgoing-273
>> Connection: Keep-Alive
2019-01-23T14:33:22.2156944Z
[BasicRepositoryConnector-repo.maven.apache.org-2-2] [DEBUG] http-outgoing-273
>> Accept-Encoding: gzip,deflate
2019-01-23T14:33:22.2362086Z
[BasicRepositoryConnector-repo.maven.apache.org-2-2] [DEBUG] http-outgoing-273
<< HTTP/1.1 200 OK
2019-01-23T14:33:22.2374374Z
[BasicRepositoryConnector-repo.maven.apache.org-2-2] [DEBUG] http-outgoing-273
<< ETag: "562636665b6ac87297513246c5bdccd2"
2019-01-23T14:33:22.2375018Z
[BasicRepositoryConnector-repo.maven.apache.org-2-2] [DEBUG] http-outgoing-273
<< Content-Type: application/java-archive
2019-01-23T14:33:22.2375081Z
[BasicRepositoryConnector-repo.maven.apache.org-2-2] [DEBUG] http-outgoing-273
<< Last-Modified: Mon, 04 Oct 2010 11:48:12 GMT
2019-01-23T14:33:22.2375129Z
[BasicRepositoryConnector-repo.maven.apache.org-2-2] [DEBUG] http-outgoing-273
<< X-Checksum-MD5: 562636665b6ac87297513246c5bdccd2
2019-01-23T14:33:22.2375193Z
[BasicRepositoryConnector-repo.maven.apache.org-2-2] [DEBUG] http-outgoing-273
<< X-Checksum-SHA1: 24ce598c94a78341c42556fe9192dad6a2822405
2019-01-23T14:33:22.2375251Z
[BasicRepositoryConnector-repo.maven.apache.org-2-2] [DEBUG] http-outgoing-273
<< Via: 1.1 varnish
2019-01-23T14:33:22.2375297Z
[BasicRepositoryConnector-repo.maven.apache.org-2-2] [DEBUG] http-outgoing-273
<< Content-Length: 164685
2019-01-23T14:33:22.2375365Z
[BasicRepositoryConnector-repo.maven.apache.org-2-2] [DEBUG] http-outgoing-273
<< Accept-Ranges: bytes
2019-01-23T14:33:22.2375412Z
[BasicRepositoryConnector-repo.maven.apache.org-2-2] [DEBUG] http-outgoing-273
<< Date: Wed, 23 Jan 2019 14:33:22 GMT
2019-01-23T14:33:22.2375474Z
[BasicRepositoryConnector-repo.maven.apache.org-2-2] [DEBUG] http-outgoing-273
<< Via: 1.1 varnish
2019-01-23T14:33:22.2375520Z
[BasicRepositoryConnector-repo.maven.apache.org-2-2] [DEBUG] http-outgoing-273
<< Age: 2869673
2019-01-23T14:33:22.2375566Z
[BasicRepositoryConnector-repo.maven.apache.org-2-2] [DEBUG] http-outgoing-273
<< Connection: keep-alive
2019-01-23T14:33:22.2375892Z
[BasicRepositoryConnector-repo.maven.apache.org-2-2] [DEBUG] http-outgoing-273
<< X-Served-By: cache-iad2139-IAD, cache-lcy19233-LCY
2019-01-23T14:33:22.2375945Z
[BasicRepositoryConnector-repo.maven.apache.org-2-2] [DEBUG] http-outgoing-273
<< X-Cache: HIT, HIT
2019-01-23T14:33:22.2375990Z
[BasicRepositoryConnector-repo.maven.apache.org-2-2] [DEBUG] http-outgoing-273
<< X-Cache-Hits: 1499, 846
2019-01-23T14:33:22.2376323Z
[BasicRepositoryConnector-repo.maven.apache.org-2-2] [DEBUG] http-outgoing-273
<< X-Timer: S1548254002.221967,VS0,VE0
2019-01-23T14:33:22.2393694Z
[BasicRepositoryConnector-repo.maven.apache.org-2-2] [DEBUG] Connection can be
kept alive indefinitely
2019-01-23T14:57:41.0120951Z
[BasicRepositoryConnector-repo.maven.apache.org-136-0] [DEBUG] CookieSpec
selected: compatibility
2019-01-23T14:57:41.0126820Z
[BasicRepositoryConnector-repo.maven.apache.org-136-0] [DEBUG] Connection
request: [route: {s}->https://repo.maven.apache.org:443][total kept alive: 3;
route allocated: 5 of 20; total allocated: 5 of 40]
2019-01-23T14:57:41.0140402Z
[BasicRepositoryConnector-repo.maven.apache.org-136-0] [DEBUG] Connection
leased: [id: 273][route: {s}->https://repo.maven.apache.org:443][total kept
alive: 2; route allocated: 5 of 20; total allocated: 5 of 40]
2019-01-23T14:57:41.0142391Z
[BasicRepositoryConnector-repo.maven.apache.org-136-0] [DEBUG]
http-outgoing-273: set socket timeout to 0
2019-01-23T14:57:41.0143407Z
[BasicRepositoryConnector-repo.maven.apache.org-136-0] [DEBUG]
http-outgoing-273: set socket timeout to 1800000
2019-01-23T14:57:41.0146554Z
[BasicRepositoryConnector-repo.maven.apache.org-136-0] [DEBUG] Executing
request GET
/maven2/org/codehaus/plexus/plexus-compiler-api/2.0/plexus-compiler-api-2.0.jar
HTTP/1.1
2019-01-23T14:57:41.0150716Z
[BasicRepositoryConnector-repo.maven.apache.org-136-0] [DEBUG] Target auth
state: UNCHALLENGED
2019-01-23T14:57:41.0153972Z
[BasicRepositoryConnector-repo.maven.apache.org-136-0] [DEBUG] Proxy auth
state: UNCHALLENGED
2019-01-23T14:57:41.0157857Z
[BasicRepositoryConnector-repo.maven.apache.org-136-0] [DEBUG]
http-outgoing-273 >> GET
/maven2/org/codehaus/plexus/plexus-compiler-api/2.0/plexus-compiler-api-2.0.jar
HTTP/1.1
2019-01-23T14:57:41.0163297Z
[BasicRepositoryConnector-repo.maven.apache.org-136-0] [DEBUG]
http-outgoing-273 >> Cache-control: no-cache
2019-01-23T14:57:41.0166277Z
[BasicRepositoryConnector-repo.maven.apache.org-136-0] [DEBUG]
http-outgoing-273 >> Cache-store: no-store
2019-01-23T14:57:41.0166453Z
[BasicRepositoryConnector-repo.maven.apache.org-136-0] [DEBUG]
http-outgoing-273 >> Pragma: no-cache
2019-01-23T14:57:41.0166718Z
[BasicRepositoryConnector-repo.maven.apache.org-136-0] [DEBUG]
http-outgoing-273 >> User-Agent: Apache-Maven/3.6.0 (Java 1.8.0_181; Windows
Server 2016 10.0)
2019-01-23T14:57:41.0166869Z
[BasicRepositoryConnector-repo.maven.apache.org-136-0] [DEBUG]
http-outgoing-273 >> Host: repo.maven.apache.org
2019-01-23T14:57:41.0167008Z
[BasicRepositoryConnector-repo.maven.apache.org-136-0] [DEBUG]
http-outgoing-273 >> Connection: Keep-Alive
2019-01-23T14:57:41.0167129Z
[BasicRepositoryConnector-repo.maven.apache.org-136-0] [DEBUG]
http-outgoing-273 >> Accept-Encoding: gzip,deflate
2019-01-23T14:58:02.5410218Z
[BasicRepositoryConnector-repo.maven.apache.org-136-0] [DEBUG]
http-outgoing-273: Close connection
2019-01-23T14:58:02.5412948Z
[BasicRepositoryConnector-repo.maven.apache.org-136-0] [DEBUG]
http-outgoing-273: Shutdown connection
2019-01-23T14:58:02.5413105Z
[BasicRepositoryConnector-repo.maven.apache.org-136-0] [DEBUG] Connection
discarded
2019-01-23T14:58:02.5413336Z
[BasicRepositoryConnector-repo.maven.apache.org-136-0] [DEBUG] Connection
released: [id: 273][route: {s}->https://repo.maven.apache.org:443][total kept
alive: 3; route allocated: 4 of 20; total allocated: 4 of 40]
2019-01-23T14:58:02.5430190Z
[BasicRepositoryConnector-repo.maven.apache.org-136-0] [INFO] I/O exception
(java.net.SocketException) caught when processing request to
{s}->https://repo.maven.apache.org:443: Connection reset
2019-01-23T14:58:02.5431510Z
[BasicRepositoryConnector-repo.maven.apache.org-136-0] [DEBUG] Connection reset
{noformat}
What baffles me is that between the last get and the closure there is a 20
second gap and no response. I also do not understand the two consecutive
settings of socket timeout.
Here is the prelast run:
{noformat}
2019-01-23T14:51:53.4428503Z
[BasicRepositoryConnector-repo.maven.apache.org-126-4] [DEBUG] Connection
request: [route: {s}->https://repo.maven.apache.org:443][total kept alive: 3;
route allocated: 5 of 20; total allocated: 5 of 40]
2019-01-23T14:51:53.4428569Z
[BasicRepositoryConnector-repo.maven.apache.org-126-4] [DEBUG] Connection
leased: [id: 273][route: {s}->https://repo.maven.apache.org:443][total kept
alive: 2; route allocated: 5 of 20; total allocated: 5 of 40]
2019-01-23T14:51:53.4428617Z
[BasicRepositoryConnector-repo.maven.apache.org-126-4] [DEBUG]
http-outgoing-273: set socket timeout to 0
2019-01-23T14:51:53.4428664Z
[BasicRepositoryConnector-repo.maven.apache.org-126-4] [DEBUG]
http-outgoing-273: set socket timeout to 1800000
2019-01-23T14:51:53.4428738Z
[BasicRepositoryConnector-repo.maven.apache.org-126-4] [DEBUG] Executing
request GET /maven2/com/google/inject/guice/4.2.0/guice-4.2.0-no_aop.jar.sha1
HTTP/1.1
2019-01-23T14:51:53.4428785Z
[BasicRepositoryConnector-repo.maven.apache.org-126-4] [DEBUG] Target auth
state: UNCHALLENGED
2019-01-23T14:51:53.4428830Z
[BasicRepositoryConnector-repo.maven.apache.org-126-4] [DEBUG] Proxy auth
state: UNCHALLENGED
2019-01-23T14:51:53.4428892Z
[BasicRepositoryConnector-repo.maven.apache.org-126-4] [DEBUG]
http-outgoing-273 >> GET
/maven2/com/google/inject/guice/4.2.0/guice-4.2.0-no_aop.jar.sha1 HTTP/1.1
2019-01-23T14:51:53.4428939Z
[BasicRepositoryConnector-repo.maven.apache.org-126-4] [DEBUG]
http-outgoing-273 >> Cache-control: no-cache
2019-01-23T14:51:53.4428997Z
[BasicRepositoryConnector-repo.maven.apache.org-126-4] [DEBUG]
http-outgoing-273 >> Cache-store: no-store
2019-01-23T14:51:53.4429043Z
[BasicRepositoryConnector-repo.maven.apache.org-126-4] [DEBUG]
http-outgoing-273 >> Pragma: no-cache
2019-01-23T14:51:53.4429106Z
[BasicRepositoryConnector-repo.maven.apache.org-126-4] [DEBUG]
http-outgoing-273 >> User-Agent: Apache-Maven/3.6.0 (Java 1.8.0_181; Windows
Server 2016 10.0)
2019-01-23T14:51:53.4429165Z
[BasicRepositoryConnector-repo.maven.apache.org-126-4] [DEBUG]
http-outgoing-273 >> Host: repo.maven.apache.org
2019-01-23T14:51:53.4429211Z
[BasicRepositoryConnector-repo.maven.apache.org-126-4] [DEBUG]
http-outgoing-273 >> Connection: Keep-Alive
2019-01-23T14:51:53.4429256Z
[BasicRepositoryConnector-repo.maven.apache.org-126-4] [DEBUG]
http-outgoing-273 >> Accept-Encoding: gzip,deflate
2019-01-23T14:51:53.4431030Z
[BasicRepositoryConnector-repo.maven.apache.org-126-4] [DEBUG]
http-outgoing-273 << HTTP/1.1 200 OK
2019-01-23T14:51:53.4431087Z
[BasicRepositoryConnector-repo.maven.apache.org-126-4] [DEBUG]
http-outgoing-273 << ETag: "d1e0dfac1fd9640a67ab4f378d663bd4"
2019-01-23T14:51:53.4431131Z
[BasicRepositoryConnector-repo.maven.apache.org-126-4] [DEBUG]
http-outgoing-273 << Content-Type: text/plain
2019-01-23T14:51:53.4431187Z
[BasicRepositoryConnector-repo.maven.apache.org-126-4] [DEBUG]
http-outgoing-273 << Last-Modified: Wed, 28 Feb 2018 18:52:07 GMT
2019-01-23T14:51:53.4431232Z
[BasicRepositoryConnector-repo.maven.apache.org-126-4] [DEBUG]
http-outgoing-273 << X-Checksum-MD5: d1e0dfac1fd9640a67ab4f378d663bd4
2019-01-23T14:51:53.4431278Z
[BasicRepositoryConnector-repo.maven.apache.org-126-4] [DEBUG]
http-outgoing-273 << X-Checksum-SHA1: 0f934090b577d2b062b3ea50f43a7c05bc7727a2
2019-01-23T14:51:53.4431502Z
[BasicRepositoryConnector-repo.maven.apache.org-126-4] [DEBUG]
http-outgoing-273 << Via: 1.1 varnish
2019-01-23T14:51:53.4431549Z
[BasicRepositoryConnector-repo.maven.apache.org-126-4] [DEBUG]
http-outgoing-273 << Content-Length: 40
2019-01-23T14:51:53.4431606Z
[BasicRepositoryConnector-repo.maven.apache.org-126-4] [DEBUG]
http-outgoing-273 << Accept-Ranges: bytes
2019-01-23T14:51:53.4431663Z
[BasicRepositoryConnector-repo.maven.apache.org-126-4] [DEBUG]
http-outgoing-273 << Date: Wed, 23 Jan 2019 14:51:53 GMT
2019-01-23T14:51:53.4431705Z
[BasicRepositoryConnector-repo.maven.apache.org-126-4] [DEBUG]
http-outgoing-273 << Via: 1.1 varnish
2019-01-23T14:51:53.4431759Z
[BasicRepositoryConnector-repo.maven.apache.org-126-4] [DEBUG]
http-outgoing-273 << Age: 3220008
2019-01-23T14:51:53.4431803Z
[BasicRepositoryConnector-repo.maven.apache.org-126-4] [DEBUG]
http-outgoing-273 << Connection: keep-alive
2019-01-23T14:51:53.4431848Z
[BasicRepositoryConnector-repo.maven.apache.org-126-4] [DEBUG]
http-outgoing-273 << X-Served-By: cache-iad2125-IAD, cache-lcy19233-LCY
2019-01-23T14:51:53.4431903Z
[BasicRepositoryConnector-repo.maven.apache.org-126-4] [DEBUG]
http-outgoing-273 << X-Cache: HIT, HIT
2019-01-23T14:51:53.4432058Z
[BasicRepositoryConnector-repo.maven.apache.org-126-4] [DEBUG]
http-outgoing-273 << X-Cache-Hits: 1, 1
2019-01-23T14:51:53.4432102Z
[BasicRepositoryConnector-repo.maven.apache.org-126-4] [DEBUG]
http-outgoing-273 << X-Timer: S1548255113.354913,VS0,VE0
2019-01-23T14:51:53.4432157Z
[BasicRepositoryConnector-repo.maven.apache.org-126-4] [DEBUG] Connection can
be kept alive indefinitely
2019-01-23T14:51:53.4432203Z
[BasicRepositoryConnector-repo.maven.apache.org-126-4] [DEBUG] Connection [id:
273][route: {s}->https://repo.maven.apache.org:443] can be kept alive
indefinitely
2019-01-23T14:51:53.4432246Z
[BasicRepositoryConnector-repo.maven.apache.org-126-4] [DEBUG]
http-outgoing-273: set socket timeout to 0
2019-01-23T14:51:53.4432308Z
[BasicRepositoryConnector-repo.maven.apache.org-126-4] [DEBUG] Connection
released: [id: 273][route: {s}->https://repo.maven.apache.org:443][total kept
alive: 3; route allocated: 5 of 20; total allocated: 5 of 40]
2019-01-23T14:51:53.4432370Z
[BasicRepositoryConnector-repo.maven.apache.org-126-4] [INFO] Downloaded from
central:
https://repo.maven.apache.org/maven2/com/google/inject/guice/4.2.0/guice-4.2.0-no_aop.jar
(521 kB at 1.5 MB/s)
{noformat}
There is a 6 min gap between prelast and last. The connection should have been
invalidated and not reused.
[~olegk], can you spot the bug here? I can't for the moment.
[~cdomsch], is there a change to get a wireshark capture of that? I assume
there is a {{RST}} somewhere in between.
> Connection reset while downloading artefacts in cloud environment (Azure)
> -------------------------------------------------------------------------
>
> Key: WAGON-545
> URL: https://issues.apache.org/jira/browse/WAGON-545
> Project: Maven Wagon
> Issue Type: Bug
> Components: wagon-http
> Affects Versions: 3.2.0
> Environment: Microsoft Azure 'Hosted VS2017'
> Reporter: Christian Domsch
> Priority: Major
> Fix For: waiting-for-feedback
>
> Attachments: log_10_310.zip, log_10_311.zip
>
>
> We are building a huge multi-module project in the azure cloud and experience
> random connection resets during our build due to probably the same issue as
> in WAGON-486. Since it is stated by Microsoft that they terminate connections
> that are idle for longer than four minutes (see solution comment
> [here|https://developercommunity.visualstudio.com/content/problem/357696/maven-project-build-failing-with-connection-reset.html],
> I set -Dmaven.wagon.httpconnectionManager.ttlSeconds=120. Also, disabling
> the http pool does not solve the problem. Attached are logs from out main
> build with logging turned on for the wagon components, as mentioned in the
> comment section of WAGON-486.
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
