Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

HTTPS requests stop working - Certificate #1961

Closed
biozit opened this issue Mar 14, 2023 · 6 comments
Closed

HTTPS requests stop working - Certificate #1961

biozit opened this issue Mar 14, 2023 · 6 comments
Assignees
@abh3
Labels
Pending Info Waiting on additional information from issue reporter

Comments

@biozit
Copy link
Contributor

biozit commented Mar 14, 2023

Hi All,

I am using XrootD 5.5.3, but at random time the HTTPS requests stop working. The IPv6 is disabled, a restart on the service "fixes" the problem.

This is the request. It hangs and gets a timeout after 1800 seconds:

./gfal-copy -E /tmp/x509up_u46903 -f https://cf-ac-uk-cache.nationalresearchplatform.org:8443/user/ligo/test_access/access_ligo .

The certificate:

openssl x509 -in /tmp/x509up_u46903 -noout -dates -subject
notBefore=Mar 14 16:48:47 2023 GMT
notAfter=Mar 26 05:53:47 2023 GMT
subject=DC = org, DC = cilogon, C = US, O = LIGO, CN = Fabio Andrijauskas fabio.andrijauskas@ligo.org

This is the log:

`230314 16:54:05 11565 Xrd_Sched: running monitor window clock inq=0
230314 16:54:05 11565 Xrd_Sched: scheduling monitor window clock in 5 seconds
230314 16:54:10 11394 Xrd_Sched: running monitor window clock inq=0
230314 16:54:10 11394 Xrd_Sched: scheduling monitor window clock in 5 seconds
230314 16:54:10 11474 Xrd_Sched: running main accept inq=0
230314 16:54:10 11644 Xrd_Inet: Accepted connection on port 8443 from 1088@ldas-grid.ligo.caltech.edu
230314 16:54:10 11644 anon.0:1088@ldas-grid.ligo.caltech.edu http_Protocol: received dlen: 16
230314 16:54:10 11644 anon.0:1088@ldas-grid.ligo.caltech.edu http_Protocol: received dump: 22 03 01 02 00 01 00 01 -04 03 03 116 43 05 97 00
230314 16:54:10 11644 anon.0:1088@ldas-grid.ligo.caltech.edu http_Protocol: This does not look like http at pos 0
230314 16:54:10 11644 anon.0:1088@ldas-grid.ligo.caltech.edu http_Protocol: This may look like https
230314 16:54:10 11644 anon.0:1088@ldas-grid.ligo.caltech.edu http_Protocol: Protocol matched. https: True
230314 16:54:10 11644 anon.0:1088@ldas-grid.ligo.caltech.edu Xrd_Poll: FD 1088 attached to poller 2; num=791
230314 16:54:10 11644 anon.0:1088@ldas-grid.ligo.caltech.edu http_Protocol: Process. lp:0x489fa008 reqstate: 0
230314 16:54:10 11644 anon.0:1088@ldas-grid.ligo.caltech.edu http_Protocol: Setting host: [::ffff:131.215.113.168]
230314 16:54:10 11644 anon.0:1088@ldas-grid.ligo.caltech.edu http_Protocol: Entering SSL_accept...
230314 16:54:10 11644 anon.0:1088@ldas-grid.ligo.caltech.edu http_Protocol: SSL_accept returned :1
230314 16:54:10 11644 anon.0:1088@ldas-grid.ligo.caltech.edu http_Security: Subject name is : '/DC=org/DC=cilogon/C=US/O=LIGO/CN=Fabio Andrijauskas fabio.andrijauskas@ligo.org'; hash is 1fa32e3f.0
230314 16:54:10 11644 anon.0:1088@ldas-grid.ligo.caltech.edu http_Security: Extracting auth info.
230314 16:54:10 11644 anon.0:1088@ldas-grid.ligo.caltech.edu http_Security: Certificate data extraction failed: /DC=org/DC=cilogon/C=US/O=LIGO/CN=Fabio Andrijauskas fabio.andrijauskas@ligo.org Failed. err: -1
230314 16:54:10 11644 anon.0:1088@ldas-grid.ligo.caltech.edu http_Security: No VOMS information for DN: /DC=org/DC=cilogon/C=US/O=LIGO/CN=Fabio Andrijauskas fabio.andrijauskas@ligo.org
230314 16:54:10 11644 sysXrdOucGMap::dn2user: no valid match found for DN '/DC=org/DC=cilogon/C=US/O=LIGO/CN=Fabio Andrijauskas fabio.andrijauskas@ligo.org'
230314 16:54:10 11644 anon.0:1088@ldas-grid.ligo.caltech.edu http_Security: Mapping name: /DC=org/DC=cilogon/C=US/O=LIGO/CN=Fabio Andrijauskas fabio.andrijauskas@ligo.org Failed. err: -14
230314 16:54:10 11644 anon.0:1088@ldas-grid.ligo.caltech.edu http_Security: Will fallback name to subject hash: 1fa32e3f.0
http Protocol 'https'
http Name '1fa32e3f.0'
http Host '[::ffff:131.215.113.168]'
http Vorg ''
http Role ''
http Grps ''
http Caps ''
http Pidn ''
http Mon '/DC=org/DC=cilogon/C=US/O=LIGO/CN=Fabio Andrijauskas fabio.andrijauskas@ligo.org'
http Crlen 0
http ueid 0
http uid 0
http gid 0
230314 16:54:10 11644 http_Protocol: getDataOneShot BuffAvailable: 1048576 maxread: 1048576
230314 16:54:10 11644 http_Protocol: getDataOneShot sslavail: 1048576
230314 16:54:11 11644 http_Protocol: read 279 of 1048576 bytes
230314 16:54:11 11644 http_Protocol: rc:50 got hdr line: POST /user/ligo/test_access/access_ligo HTTP/1.1

230314 16:54:11 11644 http_Protocol: Parsing first line: POST /user/ligo/test_access/access_ligo HTTP/1.1

230314 16:54:11 11644 http_Protocol: rc:55 got hdr line: User-Agent: gfal2-util/1.8.0 gfal2/2.21.3 neon/0.0.29

230314 16:54:11 11644 http_Protocol: rc:14 got hdr line: Keep-Alive:

230314 16:54:11 11644 http_Protocol: rc:24 got hdr line: Connection: Keep-Alive

230314 16:54:11 11644 http_Protocol: rc:14 got hdr line: TE: trailers

230314 16:54:11 11644 http_Protocol: rc:56 got hdr line: Host: cf-ac-uk-cache.nationalresearchplatform.org:8443

230314 16:54:11 11644 http_Protocol: rc:44 got hdr line: Content-Type: application/macaroon-request

230314 16:54:11 11644 http_Protocol: rc:20 got hdr line: Content-Length: 61

230314 16:54:11 11644 http_Protocol: rc:2 got hdr line:

230314 16:54:11 11644 http_Protocol: rc:2 detected header end.
230314 16:54:11 11644 http_Protocol: BuffgetData: requested 61 bytes
230314 16:54:11 11644 http_Protocol: BuffgetData: need to read 61 bytes
230314 16:54:11 11644 http_Protocol: getDataOneShot BuffAvailable: 1048576 maxread: 61
230314 16:54:11 11644 http_Protocol: getDataOneShot sslavail: 61
230314 16:54:11 11644 http_Protocol: read 61 of 61 bytes
230314 16:54:11 11644 anon.0:1088@ldas-grid.ligo.caltech.edu http_Protocol: Sending resp: 200 header len:87
230314 16:54:11 11644 http_Protocol: Sending 87 bytes
230314 16:54:11 11644 http_Protocol: Sending 465 bytes
230314 16:54:11 11644 http_Req: XrdHttpReq request ended.
230314 16:54:11 11644 anon.0:1088@ldas-grid.ligo.caltech.edu http_Protocol: Process is exiting rc:1
230314 16:54:11 11644 Xrd_Poll: Poller 2 enabled anon.0:1088@ldas-grid.ligo.caltech.edu
230314 16:54:11 11474 Xrd_Inet: Accepted connection on port 8443 from 1025@ldas-grid.ligo.caltech.edu
230314 16:54:11 11637 Xrd_Sched: running main accept inq=0
230314 16:54:11 11474 anon.0:1025@ldas-grid.ligo.caltech.edu http_Protocol: received dlen: 16
230314 16:54:11 11474 anon.0:1025@ldas-grid.ligo.caltech.edu http_Protocol: received dump: 22 03 01 02 00 01 00 01 -04 03 03 -06 -121 -36 -122 00
230314 16:54:11 11474 anon.0:1025@ldas-grid.ligo.caltech.edu http_Protocol: This does not look like http at pos 0
230314 16:54:11 11474 anon.0:1025@ldas-grid.ligo.caltech.edu http_Protocol: This may look like https
230314 16:54:11 11474 anon.0:1025@ldas-grid.ligo.caltech.edu http_Protocol: Protocol matched. https: True
230314 16:54:11 11474 anon.0:1025@ldas-grid.ligo.caltech.edu Xrd_Poll: FD 1025 attached to poller 2; num=792
230314 16:54:11 11474 anon.0:1025@ldas-grid.ligo.caltech.edu http_Protocol: Process. lp:0x43774310 reqstate: 0
230314 16:54:11 11474 anon.0:1025@ldas-grid.ligo.caltech.edu http_Protocol: Setting host: [::ffff:131.215.113.168]
230314 16:54:11 11474 anon.0:1025@ldas-grid.ligo.caltech.edu http_Protocol: Entering SSL_accept...
230314 16:54:11 11474 anon.0:1025@ldas-grid.ligo.caltech.edu http_Protocol: SSL_accept returned :1
230314 16:54:11 11474 anon.0:1025@ldas-grid.ligo.caltech.edu http_Security: Subject name is : '/DC=org/DC=cilogon/C=US/O=LIGO/CN=Fabio Andrijauskas fabio.andrijauskas@ligo.org'; hash is 1fa32e3f.0
230314 16:54:11 11474 anon.0:1025@ldas-grid.ligo.caltech.edu http_Security: Extracting auth info.
230314 16:54:11 11474 anon.0:1025@ldas-grid.ligo.caltech.edu http_Security: Certificate data extraction failed: /DC=org/DC=cilogon/C=US/O=LIGO/CN=Fabio Andrijauskas fabio.andrijauskas@ligo.org Failed. err: -1
230314 16:54:11 11474 anon.0:1025@ldas-grid.ligo.caltech.edu http_Security: No VOMS information for DN: /DC=org/DC=cilogon/C=US/O=LIGO/CN=Fabio Andrijauskas fabio.andrijauskas@ligo.org
230314 16:54:11 11474 sysXrdOucGMap::dn2user: no valid match found for DN '/DC=org/DC=cilogon/C=US/O=LIGO/CN=Fabio Andrijauskas fabio.andrijauskas@ligo.org'
230314 16:54:11 11474 anon.0:1025@ldas-grid.ligo.caltech.edu http_Security: Mapping name: /DC=org/DC=cilogon/C=US/O=LIGO/CN=Fabio Andrijauskas fabio.andrijauskas@ligo.org Failed. err: -14
230314 16:54:11 11474 anon.0:1025@ldas-grid.ligo.caltech.edu http_Security: Will fallback name to subject hash: 1fa32e3f.0
http Protocol 'https'
http Name '1fa32e3f.0'
http Host '[::ffff:131.215.113.168]'
http Vorg ''
http Role ''
http Grps ''
http Caps ''
http Pidn ''
http Mon '/DC=org/DC=cilogon/C=US/O=LIGO/CN=Fabio Andrijauskas fabio.andrijauskas@ligo.org'
http Crlen 0
http ueid 0
http uid 0
http gid 0
230314 16:54:11 11474 http_Protocol: getDataOneShot BuffAvailable: 1048576 maxread: 1048576
230314 16:54:11 11474 http_Protocol: getDataOneShot sslavail: 1048576
230314 16:54:11 11474 http_Protocol: read 677 of 1048576 bytes
230314 16:54:11 11474 http_Protocol: rc:54 got hdr line: PROPFIND /user/ligo/test_access/access_ligo HTTP/1.1

230314 16:54:11 11474 http_Protocol: Parsing first line: PROPFIND /user/ligo/test_access/access_ligo HTTP/1.1

230314 16:54:11 11474 http_Protocol: rc:55 got hdr line: User-Agent: gfal2-util/1.8.0 gfal2/2.21.3 neon/0.0.29

230314 16:54:11 11474 http_Protocol: rc:14 got hdr line: Keep-Alive:

230314 16:54:11 11474 http_Protocol: rc:24 got hdr line: Connection: Keep-Alive

230314 16:54:11 11474 http_Protocol: rc:14 got hdr line: TE: trailers

230314 16:54:11 11474 http_Protocol: rc:56 got hdr line: Host: cf-ac-uk-cache.nationalresearchplatform.org:8443

230314 16:54:11 11474 http_Protocol: rc:10 got hdr line: Depth: 0

230314 16:54:11 11474 http_Protocol: rc:448 got hdr line: Authorization: Bearer MDAyM2xvY2F0aW9uIENBUkRJRkZfVUtfT1NERl9DQUNIRQowMDM0aWRlbnRpZmllciAxOTYyZjliMC1jODIxLTQ3NjAtYTRlOS0xMjQ4OTQ5MjhhODAKMDAxOGNpZCBuYW1lOjFmYTMyZTNmLjAKMDAyZGNpZCBhY3Rpdml0eTpSRUFEX01FVEFEQVRBLERPV05MT0FELExJU1QKMDAxZmNpZCBhY3Rpdml0eTpMSVNULERPV05MT0FECjAwMzBjaWQgcGF0aDovdXNlci9saWdvL3Rlc3RfYWNjZXNzL2FjY2Vzc19saWdvCjAwMjRjaWQgYmVmb3JlOjIwMjMtMDMtMTRUMTk6NTQ6MTFaCjAwMmZzaWduYXR1cmUgRcbATrKGH9-V2QFsc3IBbi_k3aZqPmvFpGKmRzsxMcgK

230314 16:54:11 11474 http_Protocol: rc:2 got hdr line:

230314 16:54:11 11474 http_Protocol: rc:2 detected header end.
230314 16:54:11 11474 XrootdBridge: 1fa32e3f.417786:1025@ldas-grid.ligo.caltech.edu login as 1fa32e3f.0
230314 16:54:11 11474 Xrd_Poll: Poller 2 enabled 1fa32e3f.417786:1025@ldas-grid.ligo.caltech.edu
230314 16:54:15 11492 Xrd_Sched: running monitor window clock inq=0
230314 16:54:15 11492 Xrd_Sched: scheduling monitor window clock in 5 seconds
230314 16:54:20 11646 Xrd_Sched: running monitor window clock inq=0
230314 16:54:20 11646 Xrd_Sched: scheduling monitor window clock in 5 seconds
230314 16:54:25 11569 Xrd_Sched: running monitor window clock inq=0
230314 16:54:25 11569 Xrd_Sched: scheduling monitor window clock in 5 seconds
230314 16:54:29 11637 Xrd_Inet: Accepted connection on port 8443 from 1092@hcc-mon2.unl.edu
230314 16:54:29 11643 Xrd_Sched: running main accept inq=0
230314 16:54:29 11637 anon.0:1092@hcc-mon2.unl.edu http_Protocol: received dlen: 16
230314 16:54:29 11637 anon.0:1092@hcc-mon2.unl.edu http_Protocol: received dump: 22 03 01 00 -32 01 00 00 -36 03 03 45 65 60 102 00
230314 16:54:29 11637 anon.0:1092@hcc-mon2.unl.edu http_Protocol: This does not look like http at pos 0
230314 16:54:29 11637 anon.0:1092@hcc-mon2.unl.edu http_Protocol: This may look like https
230314 16:54:29 11637 anon.0:1092@hcc-mon2.unl.edu http_Protocol: Protocol matched. https: True
230314 16:54:29 11637 anon.0:1092@hcc-mon2.unl.edu Xrd_Poll: FD 1092 attached to poller 0; num=793
230314 16:54:29 11637 anon.0:1092@hcc-mon2.unl.edu http_Protocol: Process. lp:0x489fac28 reqstate: 0
230314 16:54:29 11637 anon.0:1092@hcc-mon2.unl.edu http_Protocol: Setting host: [::ffff:129.93.244.204]
230314 16:54:29 11637 anon.0:1092@hcc-mon2.unl.edu http_Protocol: Entering SSL_accept...
230314 16:54:29 11637 anon.0:1092@hcc-mon2.unl.edu http_Protocol: SSL_accept returned :1
230314 16:54:29 11637 anon.0:1092@hcc-mon2.unl.edu http_Security: Subject name is : '/DC=org/DC=cilogon/C=US/O=LIGO/CN=Fabio Andrijauskas fabio.andrijauskas@ligo.org'; hash is 1fa32e3f.0
230314 16:54:29 11637 anon.0:1092@hcc-mon2.unl.edu http_Security: Extracting auth info.
230314 16:54:29 11637 anon.0:1092@hcc-mon2.unl.edu http_Security: Certificate data extraction failed: /DC=org/DC=cilogon/C=US/O=LIGO/CN=Fabio Andrijauskas fabio.andrijauskas@ligo.org Failed. err: -1
230314 16:54:29 11637 anon.0:1092@hcc-mon2.unl.edu http_Security: No VOMS information for DN: /DC=org/DC=cilogon/C=US/O=LIGO/CN=Fabio Andrijauskas fabio.andrijauskas@ligo.org
230314 16:54:29 11637 sysXrdOucGMap::dn2user: no valid match found for DN '/DC=org/DC=cilogon/C=US/O=LIGO/CN=Fabio Andrijauskas fabio.andrijauskas@ligo.org'
230314 16:54:29 11637 anon.0:1092@hcc-mon2.unl.edu http_Security: Mapping name: /DC=org/DC=cilogon/C=US/O=LIGO/CN=Fabio Andrijauskas fabio.andrijauskas@ligo.org Failed. err: -14
230314 16:54:29 11637 anon.0:1092@hcc-mon2.unl.edu http_Security: Will fallback name to subject hash: 1fa32e3f.0
http Protocol 'https'
http Name '1fa32e3f.0'
http Host '[::ffff:129.93.244.204]'
http Vorg ''
http Role ''
http Grps ''
http Caps ''
http Pidn ''
http Mon '/DC=org/DC=cilogon/C=US/O=LIGO/CN=Fabio Andrijauskas fabio.andrijauskas@ligo.org'
http Crlen 0
http ueid 0
http uid 0
http gid 0
230314 16:54:29 11637 http_Protocol: getDataOneShot BuffAvailable: 1048576 maxread: 1048576
230314 16:54:29 11637 http_Protocol: getDataOneShot sslavail: 1048576
230314 16:54:29 11637 http_Protocol: read 145 of 1048576 bytes
230314 16:54:29 11637 http_Protocol: rc:49 got hdr line: GET /user/ligo/test_access/access_ligo HTTP/1.1

230314 16:54:29 11637 http_Protocol: Parsing first line: GET /user/ligo/test_access/access_ligo HTTP/1.1

230314 16:54:29 11637 http_Protocol: rc:25 got hdr line: User-Agent: curl/7.29.0

230314 16:54:29 11637 http_Protocol: rc:56 got hdr line: Host: cf-ac-uk-cache.nationalresearchplatform.org:8443

230314 16:54:29 11637 http_Protocol: rc:13 got hdr line: Accept: /

230314 16:54:29 11637 http_Protocol: rc:2 got hdr line:

230314 16:54:29 11637 http_Protocol: rc:2 detected header end.
230314 16:54:29 11637 XrootdBridge: 1fa32e3f.417787:1092@hcc-mon2.unl.edu login as 1fa32e3f.0
230314 16:54:29 11637 Xrd_Poll: Poller 0 enabled 1fa32e3f.417787:1092@hcc-mon2.unl.edu
230314 16:54:30 11434 Xrd_Sched: running GStream inq=3
230314 16:54:30 11434 Xrd_Sched: scheduling GStream in 30 seconds
230314 16:54:30 11564 Xrd_Sched: running GStream inq=0
230314 16:54:30 11564 Xrd_Sched: scheduling GStream in 30 seconds
230314 16:54:30 11466 Xrd_Sched: running GStream inq=0
230314 16:54:30 11466 Xrd_Sched: scheduling GStream in 30 seconds
230314 16:54:30 11642 Xrd_Sched: running monitor window clock inq=0
230314 16:54:30 11642 Xrd_Sched: scheduling monitor window clock in 5 seconds
230314 16:54:31 11639 Xrd_Sched: running monitor fstat inq=0
230314 16:54:31 11639 Xrd_Sched: scheduling monitor fstat in 60 seconds
230314 16:54:35 11565 Xrd_Sched: running monitor window clock inq=0
230314 16:54:35 11565 Xrd_Sched: scheduling monitor window clock in 5 seconds
230314 16:54:40 2330 unknown.417784:1085@hcc-mon2.unl.edu Xrd_Poll: Link 1085 terminating: hangup
230314 16:54:40 11394 Xrd_Sched: running unknown.417784:1085@hcc-mon2.unl.edu inq=0
230314 16:54:40 11394 http_Protocol: Cleanup
230314 16:54:40 11394 http_Protocol: SSL_shutdown failed
230314 16:54:40 11394 http_Protocol: Reset
230314 16:54:40 11394 http_Req: XrdHttpReq request ended.
230314 16:54:40 11394 XrootdXeq: unknown.417784:1085@hcc-mon2.unl.edu disc 0:01:00
230314 16:54:40 11394 unknown.417784:1085@hcc-mon2.unl.edu Xrd_Poll: Poller 2 removing FD 1085
230314 16:54:40 11394 unknown.417784:1085@hcc-mon2.unl.edu Xrd_Poll: FD 1085 detached from poller 2; num=791
230314 16:54:40 11644 Xrd_Sched: running monitor window clock inq=0
230314 16:54:40 11644 Xrd_Sched: scheduling monitor window clock in 5 seconds
230314 16:54:41 11643 Xrd_Inet: Accepted connection on port 8443 from 1096@hcc-mon2.unl.edu
230314 16:54:41 11474 Xrd_Sched: running main accept inq=0
230314 16:54:41 11643 anon.0:1096@hcc-mon2.unl.edu http_Protocol: received dlen: 16
230314 16:54:41 11643 anon.0:1096@hcc-mon2.unl.edu http_Protocol: received dump: 22 03 01 01 108 01 00 01 104 03 03 78 -34 -10 -36 00
230314 16:54:41 11643 anon.0:1096@hcc-mon2.unl.edu http_Protocol: This does not look like http at pos 0
230314 16:54:41 11643 anon.0:1096@hcc-mon2.unl.edu http_Protocol: This may look like https
230314 16:54:41 11643 anon.0:1096@hcc-mon2.unl.edu http_Protocol: Protocol matched. https: True
230314 16:54:41 11643 anon.0:1096@hcc-mon2.unl.edu Xrd_Poll: FD 1096 attached to poller 2; num=792
230314 16:54:41 11643 anon.0:1096@hcc-mon2.unl.edu http_Protocol: Process. lp:0x489fb848 reqstate: 0
230314 16:54:41 11643 anon.0:1096@hcc-mon2.unl.edu http_Protocol: Setting host: [::ffff:129.93.244.204]
230314 16:54:41 11643 anon.0:1096@hcc-mon2.unl.edu http_Protocol: Entering SSL_accept...
230314 16:54:41 11643 anon.0:1096@hcc-mon2.unl.edu http_Protocol: SSL_accept returned :1
230314 16:54:41 11643 anon.0:1096@hcc-mon2.unl.edu http_Security: No certificate found in peer chain.
http Protocol 'https'
http Name ''
http Host '[::ffff:129.93.244.204]'
http Vorg ''
http Role ''
http Grps ''
http Caps ''
http Pidn ''
http Mon ''
http Crlen 0
http ueid 0
http uid 0
http gid 0
230314 16:54:41 11643 http_Protocol: getDataOneShot BuffAvailable: 1048576 maxread: 1048576
230314 16:54:41 11643 http_Protocol: getDataOneShot sslavail: 1048576
230314 16:54:41 11643 http_Protocol: read 212 of 1048576 bytes
230314 16:54:41 11643 http_Protocol: rc:49 got hdr line: GET /user/ligo/test_access/access_ligo HTTP/1.1

230314 16:54:41 11643 http_Protocol: Parsing first line: GET /user/ligo/test_access/access_ligo HTTP/1.1

230314 16:54:41 11643 http_Protocol: rc:56 got hdr line: Host: cf-ac-uk-cache.nationalresearchplatform.org:8443

230314 16:54:41 11643 http_Protocol: rc:36 got hdr line: User-Agent: python-requests/2.14.2

230314 16:54:41 11643 http_Protocol: rc:32 got hdr line: Accept-Encoding: gzip, deflate

230314 16:54:41 11643 http_Protocol: rc:13 got hdr line: Accept: /

230314 16:54:41 11643 http_Protocol: rc:24 got hdr line: Connection: keep-alive

230314 16:54:41 11643 http_Protocol: rc:2 got hdr line:

230314 16:54:41 11643 http_Protocol: rc:2 detected header end.
230314 16:54:41 11643 XrootdBridge: unknown.417788:1096@hcc-mon2.unl.edu login as nobody
230314 16:54:41 11643 Xrd_Poll: Poller 2 enabled unknown.417788:1096@hcc-mon2.unl.edu
230314 16:54:45 11492 Xrd_Sched: running monitor window clock inq=0
230314 16:54:45 11492 Xrd_Sched: scheduling monitor window clock in 5 seconds
230314 16:54:50 11646 Xrd_Sched: running monitor window clock inq=0
230314 16:54:50 11646 Xrd_Sched: scheduling monitor window clock in 5 seconds
230314 16:54:53 11474 Xrd_Inet: Accepted connection on port 8443 from 1085@hcc-mon2.unl.edu
230314 16:54:53 11569 Xrd_Sched: running main accept inq=0
230314 16:54:53 11474 anon.0:1085@hcc-mon2.unl.edu http_Protocol: received dlen: 16
230314 16:54:53 11474 anon.0:1085@hcc-mon2.unl.edu http_Protocol: received dump: 22 03 01 01 47 01 00 01 43 03 03 -114 93 -122 -116 00
230314 16:54:53 11474 anon.0:1085@hcc-mon2.unl.edu http_Protocol: This does not look like http at pos 0
230314 16:54:53 11474 anon.0:1085@hcc-mon2.unl.edu http_Protocol: This may look like https
230314 16:54:53 11474 anon.0:1085@hcc-mon2.unl.edu http_Protocol: Protocol matched. https: True
230314 16:54:53 11474 anon.0:1085@hcc-mon2.unl.edu Xrd_Poll: FD 1085 attached to poller 1; num=793
230314 16:54:53 11474 anon.0:1085@hcc-mon2.unl.edu http_Protocol: Process. lp:0x4377f8f0 reqstate: 0
230314 16:54:53 11474 anon.0:1085@hcc-mon2.unl.edu http_Protocol: Setting host: [::ffff:129.93.244.204]
230314 16:54:53 11474 anon.0:1085@hcc-mon2.unl.edu http_Protocol: Entering SSL_accept...
230314 16:54:53 11474 anon.0:1085@hcc-mon2.unl.edu http_Protocol: SSL_accept returned :1
230314 16:54:53 11474 anon.0:1085@hcc-mon2.unl.edu http_Security: No certificate found in peer chain.
http Protocol 'https'
http Name ''
http Host '[::ffff:129.93.244.204]'
http Vorg ''
http Role ''
http Grps ''
http Caps ''
http Pidn ''
http Mon ''
http Crlen 0
http ueid 0
http uid 0
http gid 0
230314 16:54:53 11474 http_Protocol: getDataOneShot BuffAvailable: 1048576 maxread: 1048576
230314 16:54:53 11474 http_Protocol: getDataOneShot sslavail: 1048576
230314 16:54:53 11474 http_Protocol: Cleanup
230314 16:54:53 11474 http_Protocol: SSL_shutdown failed
230314 16:54:53 11474 http_Protocol: Reset
230314 16:54:53 11474 http_Req: XrdHttpReq request ended.
230314 16:54:53 11474 anon.0:1085@hcc-mon2.unl.edu Xrd_Poll: Poller 1 removing FD 1085
230314 16:54:53 11474 anon.0:1085@hcc-mon2.unl.edu Xrd_Poll: FD 1085 detached from poller 1; num=792
230314 16:54:55 11637 Xrd_Sched: running monitor window clock inq=0
230314 16:54:55 11637 Xrd_Sched: scheduling monitor window clock in 5 seconds
`
@abh3
Copy link
Member

abh3 commented Mar 14, 2023 via email

@bbockelm
Copy link
Contributor

@biozit - further, it'd be useful to have a higher debug level for xrd.trace, ofs.trace, and xrootd.trace. We can see what the HTTP layer is doing but it's not logging what's going on at the lower layers. Particularly, I think this would help:

xrd.trace all debug
xrootd.trace all
ofs.trace all debug
pfc.trace debug

There's more debugging levels to use but that's already pretty verbose -- it may double or triple the log volume over the HTTP debug logs you already have enabled. Note that this can affect performance so it's best to use only while debugging, not everywhere.

@biozit
Copy link
Contributor Author

biozit commented Mar 15, 2023

@abh3 I will test with the latest master

@abh3 abh3 added the Pending Info Waiting on additional information from issue reporter label Mar 23, 2023
@abh3
Copy link
Member

abh3 commented Oct 12, 2023

Any update on this or should we close this ticket?

@abh3 abh3 self-assigned this Oct 12, 2023
@bbockelm
Copy link
Contributor

Things have been well-behaved for awhile... let's go ahead and close.

@abh3
Copy link
Member

abh3 commented Oct 16, 2023

Closing as requested.

@abh3 abh3 closed this as completed Oct 16, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@abh3 abh3

Labels
Pending Info Waiting on additional information from issue reporter
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@bbockelm @abh3 @biozit