Advertisement
fmartinelli

dCache 2.10 CSCS java.net.SocketException: Connection reset

Feb 19th, 2016
382
0
Never
Not a member of Pastebin yet? Sign Up, it unlocks many cool features!
Bash 12.73 KB | None | 0 0
  1. 19 Feb 2016 16:19:13 (SRM-t3se01) [dKE:350032:srm2:copy:-2075958156] STATUS BEFORE: NEED_UNWRAP
  2. 19 Feb 2016 16:19:13 (SRM-t3se01) [dKE:350032:srm2:copy:-2075958156] PROCESSING 1: 53
  3. 19 Feb 2016 16:19:13 (SRM-t3se01) [dKE:350032:srm2:copy:-2075958156] STATUS AFTER: NOT_HANDSHAKING
  4. 19 Feb 2016 16:19:13 (SRM-t3se01) [dKE:350032:srm2:copy:-2075958156] initSecContext handshake finished
  5. 19 Feb 2016 16:19:13 (SRM-t3se01) [dKE:350032:srm2:copy:-2075958156] encryption alg: TLS_RSA_WITH_AES_128_CBC_SHA
  6. 19 Feb 2016 16:19:13 (SRM-t3se01) [dKE:350032:srm2:copy:-2075958156] Peer Identity is: /DC=com/DC=quovadisglobal/DC=grid/DC=switch/DC=hosts/C=CH/ST=Zuerich/L=Zuerich/O=ETH Zuerich/CN=storage01.lcg.cscs.ch Target name is: /DC=com/DC=quovadisglobal/DC=grid/DC=switch/DC=hosts/C=CH/ST=Zuerich/L=Zuerich/O=ETH Zuerich/CN=storage01.lcg.cscs.ch Limited Proxy: false
  7. 19 Feb 2016 16:19:13 (SRM-t3se01) [dKE:350032:srm2:copy:-2075958156] CLIENT_START_DEL
  8. 19 Feb 2016 16:19:13 (SRM-t3se01) [dKE:350032:srm2:copy:-2075958156] PROCESSING DATA (WRAP) 1: 1
  9. 19 Feb 2016 16:19:13 (SRM-t3se01) [dKE:350032:srm2:copy:-2075958156] exit initSecContext
  10. 19 Feb 2016 16:19:13 (SRM-t3se01) [dKE:350032:srm2:copy:-2075958156] enter initSecContext
  11. 19 Feb 2016 16:19:13 (SRM-t3se01) [dKE:350032:srm2:copy:-2075958156] Require authz with delegation: true
  12. 19 Feb 2016 16:19:13 (SRM-t3se01) [dKE:350032:srm2:copy:-2075958156] CLIENT_END_DEL
  13. 19 Feb 2016 16:19:13 (SRM-t3se01) [dKE:350032:srm2:copy:-2075958156] PROCESSING DATA (UNWRAP) 1: 597
  14. 19 Feb 2016 16:19:13 (SRM-t3se01) [dKE:350032:srm2:copy:-2075958156] PROCESSING DATA (WRAP) 1: 828
  15. 19 Feb 2016 16:19:13 (SRM-t3se01) [dKE:350032:srm2:copy:-2075958156] DONE with Handshaking and any initial cred delegation
  16. 19 Feb 2016 16:19:13 (SRM-t3se01) [dKE:350032:srm2:copy:-2075958156] exit initSecContext
  17. 19 Feb 2016 16:19:13 (SRM-t3se01) [dKE:350032:srm2:copy:-2075958156] Handshake end
  18. 19 Feb 2016 16:19:13 (SRM-t3se01) [dKE:350032:srm2:copy:-2075958156] Performing authorization.
  19. 19 Feb 2016 16:19:13 (SRM-t3se01) [dKE:350032:srm2:copy:-2075958156] org.apache.axis.i18n.resource::handleGetObject(xmlSent00)
  20. 19 Feb 2016 16:19:13 (SRM-t3se01) [dKE:350032:srm2:copy:-2075958156] XML sent:
  21. 19 Feb 2016 16:19:13 (SRM-t3se01) [dKE:350032:srm2:copy:-2075958156] ---------------------------------------------------
  22. 19 Feb 2016 16:19:13 (SRM-t3se01) [dKE:350032:srm2:copy:-2075958156] Enter: SOAPPart::saveChanges
  23. 19 Feb 2016 16:19:13 (SRM-t3se01) [dKE:350032:srm2:copy:-2075958156] enter wrap
  24. 19 Feb 2016 16:19:13 (SRM-t3se01) [dKE:350032:srm2:copy:-2075958156] PROCESSING DATA (WRAP) 1: 2518
  25. 19 Feb 2016 16:19:13 (SRM-t3se01) [dKE:350032:srm2:copy:-2075958156] exit wrap
  26. 19 Feb 2016 16:19:13 (SRM-t3se01) [dKE:350032:srm2:copy:-2075958156] POST /srm/managerv2 HTTP/1.0^M
  27. Content-Type: text/xml; charset=utf-8^M
  28. Accept: application/soap+xml, application/dime, multipart/related, text/*^M
  29. User-Agent: Axis/1.4^M
  30. Host: storage01.lcg.cscs.ch:8443^M
  31. Cache-Control: no-cache^M
  32. Pragma: no-cache^M
  33. SOAPAction: ""^M
  34. Content-Length: 2235^M
  35. ^M
  36. <?xml version="1.0" encoding="UTF-8"?><soapenv:Envelope xmlns:soapenv="http://schemas.xmlsoap.org/soap/envelope/" xmlns:xsd="http://www.w3.org/2001/XMLSchema" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance">
  37.  <soapenv:Body>
  38.   <ns1:srmPrepareToGet soapenv:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/" xmlns:ns1="http://srm.lbl.gov/StorageResourceManager">
  39.    <srmPrepareToGetRequest xsi:type="ns1:srmPrepareToGetRequest">
  40.     <authorizationID xsi:type="xsd:string" xsi:nil="true"/>
  41.     <arrayOfFileRequests xsi:type="ns1:ArrayOfTGetFileRequest">
  42.      <requestArray xsi:type="ns1:TGetFileRequest">
  43.       <sourceSURL xsi:type="xsd:anyURI">srm://storage01.lcg.cscs.ch:8443/srm/managerv2?SFN=/pnfs/lcg.cscs.ch/cms/trivcat/store/mc/RunIIFall15MiniAODv2/QCD_HT1500to2000_TuneCUETP8M1_13TeV-madgraphMLM-pythia8/MINIAODSIM/PU25nsData2015v1_76X_mcRun2_asymptotic_v12-v1/50000/7EF8B018-C4B9-E511-A55F-0025904B8934.root</sourceSURL>
  44.       <dirOption xsi:type="ns1:TDirOption" xsi:nil="true"/>
  45.      </requestArray>
  46.     </arrayOfFileRequests>
  47.     <userRequestDescription xsi:type="xsd:string" xsi:nil="true"/>
  48.     <storageSystemInfo xsi:type="ns1:ArrayOfTExtraInfo" xsi:nil="true"/>
  49.     <desiredFileStorageType xsi:type="ns1:TFileStorageType" xsi:nil="true"/>
  50.     <desiredTotalRequestTime xsi:type="xsd:int">14399997</desiredTotalRequestTime>
  51.     <desiredPinLifeTime xsi:type="xsd:int" xsi:nil="true"/>
  52.     <targetSpaceToken xsi:type="xsd:string" xsi:nil="true"/>
  53.     <targetFileRetentionPolicyInfo xsi:type="ns1:TRetentionPolicyInfo" xsi:nil="true"/>
  54.     <transferParameters xsi:type="ns1:TTransferParameters">
  55.      <accessPattern xsi:type="ns1:TAccessPattern">TRANSFER_MODE</accessPattern>
  56.      <connectionType xsi:type="ns1:TConnectionType">WAN</connectionType>
  57.      <arrayOfClientNetworks xsi:type="ns1:ArrayOfString" xsi:nil="true"/>
  58.      <arrayOfTransferProtocols xsi:type="ns1:ArrayOfString">
  59.       <stringArray xsi:type="xsd:string">gsiftp</stringArray>
  60.       <stringArray xsi:type="xsd:string">http</stringArray>
  61.       <stringArray xsi:type="xsd:string">ftp</stringArray>
  62.      </arrayOfTransferProtocols>
  63.     </transferParameters>
  64.    </srmPrepareToGetRequest>
  65.   </ns1:srmPrepareToGet>
  66.  </soapenv:Body>
  67. </soapenv:Envelope>
  68. 19 Feb 2016 16:19:13 (SRM-t3se01) [dKE:350032:srm2:copy:-2075958156] java.net.SocketException: Connection reset
  69. 19 Feb 2016 16:19:13 (SRM-t3se01) [dKE:350032:srm2:copy:-2075958156] dipose
  70. 19 Feb 2016 16:19:13 (SRM-t3se01) [dKE:350032:srm2:copy:-2075958156] Enter: SOAPPart ctor(FORM_FAULT)
  71. 19 Feb 2016 16:19:13 (SRM-t3se01) [dKE:350032:srm2:copy:-2075958156] org.apache.axis.i18n.resource::handleGetObject(setMsgForm)
  72. 19 Feb 2016 16:19:13 (SRM-t3se01) [dKE:350032:srm2:copy:-2075958156] Setting current message form to: FORM_FAULT (currentMessage is now org.apache.axis.AxisFault)
  73. 19 Feb 2016 16:19:13 (SRM-t3se01) [dKE:350032:srm2:copy:-2075958156] Exit: SOAPPart ctor()
  74. 19 Feb 2016 16:19:13 (SRM-t3se01) [dKE:350032:srm2:copy:-2075958156] org.apache.axis.i18n.resource::handleGetObject(toAxisFault00)
  75. 19 Feb 2016 16:19:13 (SRM-t3se01) [dKE:350032:srm2:copy:-2075958156] Mapping Exception to AxisFault
  76. org.apache.axis.AxisFault: ; nested exception is:
  77.         java.net.SocketException: Connection reset
  78.         at org.apache.axis.AxisFault.makeFault(AxisFault.java:101) ~[axis-1.4.jar:na]
  79.         at org.apache.axis.transport.http.HTTPSender.invoke(HTTPSender.java:154) ~[axis-1.4.jar:na]
  80.         at org.apache.axis.strategies.InvocationStrategy.visit(InvocationStrategy.java:32) ~[axis-1.4.jar:na]
  81.         at org.apache.axis.SimpleChain.doVisiting(SimpleChain.java:118) ~[axis-1.4.jar:na]
  82.         at org.apache.axis.SimpleChain.invoke(SimpleChain.java:83) ~[axis-1.4.jar:na]
  83.         at org.apache.axis.client.AxisClient.invoke(AxisClient.java:165) ~[axis-1.4.jar:na]
  84.         at org.apache.axis.client.Call.invokeEngine(Call.java:2784) [axis-1.4.jar:na]
  85.         at org.apache.axis.client.Call.invoke(Call.java:2767) [axis-1.4.jar:na]
  86.         at org.apache.axis.client.Call.invoke(Call.java:2443) [axis-1.4.jar:na]
  87.         at org.apache.axis.client.Call.invoke(Call.java:2366) [axis-1.4.jar:na]
  88.         at org.apache.axis.client.Call.invoke(Call.java:1812) [axis-1.4.jar:na]
  89.         at org.dcache.srm.v2_2.SrmSoapBindingStub.srmPrepareToGet(SrmSoapBindingStub.java:2182) [srm-common-2.13.9.jar:2.13.9]
  90.         at sun.reflect.GeneratedMethodAccessor1174.invoke(Unknown Source) ~[na:na]
  91.         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_60]
  92.         at java.lang.reflect.Method.invoke(Method.java:497) ~[na:1.8.0_60]
  93.         at org.dcache.srm.client.SRMClientV2.handleClientCall(SRMClientV2.java:263) [srm-common-2.13.9.jar:2.13.9]
  94.         at org.dcache.srm.client.SRMClientV2.srmPrepareToGet(SRMClientV2.java:503) [srm-common-2.13.9.jar:2.13.9]
  95.         at org.dcache.srm.client.RemoteTurlGetterV2.getInitialRequest(RemoteTurlGetterV2.java:206) [srm-server-2.13.9.jar:2.13.9]
  96.         at org.dcache.srm.request.CopyRequest.getTURLs(CopyRequest.java:492) [srm-server-2.13.9.jar:2.13.9]
  97.         at org.dcache.srm.request.CopyRequest.proccessRequest(CopyRequest.java:336) [srm-server-2.13.9.jar:2.13.9]
  98.         at org.dcache.srm.request.CopyRequest.run(CopyRequest.java:821) [srm-server-2.13.9.jar:2.13.9]
  99.         at org.dcache.srm.scheduler.Scheduler$JobWrapper.run(Scheduler.java:451) [srm-server-2.13.9.jar:2.13.9]
  100.         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_60]
  101.         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_60]
  102.         at java.lang.Thread.run(Thread.java:745) [na:1.8.0_60]
  103. Caused by: java.net.SocketException: Connection reset
  104.         at java.net.SocketInputStream.read(SocketInputStream.java:209) ~[na:1.8.0_60]
  105.         at java.net.SocketInputStream.read(SocketInputStream.java:141) ~[na:1.8.0_60]
  106.         at org.globus.gsi.gssapi.SSLUtil.read(SSLUtil.java:41) ~[gss-2.0.6-rc9.d.jar:na]
  107.         at org.globus.gsi.gssapi.net.impl.GSIGssInputStream.readToken(GSIGssInputStream.java:70) ~[gss-2.0.6-rc9.d.jar:na]
  108.         at org.globus.gsi.gssapi.net.impl.GSIGssInputStream.readMsg(GSIGssInputStream.java:44) ~[gss-2.0.6-rc9.d.jar:na]
  109.         at org.globus.gsi.gssapi.net.GssInputStream.hasData(GssInputStream.java:90) ~[gss-2.0.6-rc9.d.jar:na]
  110.         at org.globus.gsi.gssapi.net.GssInputStream.read(GssInputStream.java:63) ~[gss-2.0.6-rc9.d.jar:na]
  111.         at java.io.BufferedInputStream.fill(BufferedInputStream.java:246) ~[na:1.8.0_60]
  112.         at java.io.BufferedInputStream.read(BufferedInputStream.java:265) ~[na:1.8.0_60]
  113.         at org.apache.axis.transport.http.HTTPSender.readHeadersFromSocket(HTTPSender.java:583) ~[axis-1.4.jar:na]
  114.         at org.apache.axis.transport.http.HTTPSender.invoke(HTTPSender.java:143) ~[axis-1.4.jar:na]
  115.         ... 23 common frames omitted
  116. 19 Feb 2016 16:19:13 (SRM-t3se01) [dKE:350032:srm2:copy:-2075958156] srmPrepareToGet : try # 0 failed with error ; nested exception is:
  117.         java.net.SocketException: Connection reset
  118. 19 Feb 2016 16:19:13 (SRM-t3se01) [dKE:350032:srm2:copy:-2075958156]  srmPrepareToGet : try again
  119. 19 Feb 2016 16:19:13 (SRM-t3se01) [dKE:350032:srm2:copy:-2075958156] sleeping 60000 milliseconds before retrying
  120. 19 Feb 2016 16:19:14 (SRM-t3se01) [] Queued change org.eclipse.jetty.io.SelectorManager$ManagedSelector$Accept@46571a84
  121. 19 Feb 2016 16:19:14 (SRM-t3se01) [] Selector loop woken up from select, 0/0 selected
  122. 19 Feb 2016 16:19:14 (SRM-t3se01) [] Running change org.eclipse.jetty.io.SelectorManager$ManagedSelector$Accept@46571a84
  123. 19 Feb 2016 16:19:14 (SRM-t3se01) [] onOpen SelectChannelEndPoint@78ae485e{/192.33.123.120:35125<->8443,Open,in,out,-,-,0/60000,null}{io=0,kio=0,kro=0}
  124. 19 Feb 2016 16:19:14 (SRM-t3se01) [] SelectChannelEndPoint@78ae485e{/192.33.123.120:35125<->8443,Open,in,out,-,-,0/60000,null}{io=0,kio=0,kro=0} idle timeout check, elapsed: 0 ms, remaining: 60000 ms
  125. 19 Feb 2016 16:19:14 (SRM-t3se01) [] DecryptedEndPoint@106a2609{t3wn40.psi.ch/192.33.123.120:35125<->8443,Open,in,out,-,-,0/60000,null}->SelectChannelEndPoint@78ae485e{t3wn40.psi.ch/192.33.123.120:35125<->8443,Open,in,out,-,-,2/60000,null}{io=0,kio=0,kro=0} idle timeout check, elapsed: 0 ms, remaining: 60000 ms
  126. 19 Feb 2016 16:19:14 (SRM-t3se01) [] new HttpChannelOverHttp@55dd4410{r=0,c=false,a=IDLE,uri=-} -> DecryptedEndPoint@106a2609{t3wn40.psi.ch/192.33.123.120:35125<->8443,Open,in,out,-,-,0/60000,null}->SelectChannelEndPoint@78ae485e{t3wn40.psi.ch/192.33.123.120:35125<->8443,Open,in,out,-,-,2/60000,null}{io=0,kio=0,kro=0},null,HttpChannelState@1b607271{s=IDLE i=true a=null}
  127. 19 Feb 2016 16:19:14 (SRM-t3se01) [] New HTTP Connection HttpConnection@118635fb{IDLE}
  128. 19 Feb 2016 16:19:14 (SRM-t3se01) [] onOpen SslConnection@501d13ac{NEED_UNWRAP,eio=-1/-1,di=-1} -> HttpConnection@118635fb{IDLE}
  129. 19 Feb 2016 16:19:14 (SRM-t3se01) [] onOpen HttpConnection@118635fb{IDLE}
  130. 19 Feb 2016 16:19:14 (SRM-t3se01) [] fillInterested HttpConnection@118635fb{IDLE}
  131. 19 Feb 2016 16:19:14 (SRM-t3se01) [] IDLE-->FILL_INTERESTED HttpConnection@118635fb{FILL_INTERESTED}
  132. 19 Feb 2016 16:19:14 (SRM-t3se01) [] fillInterested SslConnection@501d13ac{NEED_UNWRAP,eio=-1/-1,di=-1} -> HttpConnection@118635fb{FILL_INTERESTED}
  133. 19 Feb 2016 16:19:14 (SRM-t3se01) [] IDLE-->FILL_INTERESTED SslConnection@501d13ac{NEED_UNWRAP,eio=-1/-1,di=-1} -> HttpConnection@118635fb{FILL_INTERESTED}
  134. 19 Feb 2016 16:19:14 (SRM-t3se01) [] Local interests updating 0 -> 1 for SelectChannelEndPoint@78ae485e{t3wn40.psi.ch/192.33.123.120:35125<->8443,Open,in,out,R,-,0/60000,SslConnection}{io=1,kio=0,kro=0}
  135. 19 Feb 2016 16:19:14 (SRM-t3se01) [] Running change org.eclipse.jetty.io.SelectChannelEndPoint$1@6fdf207b
Advertisement
Add Comment
Please, Sign In to add comment
Advertisement