HTTPAPIR4 gsk_secure_soc_write rc=406 issue

Discussions related to HTTPAPI (An HTTP Client Package for RPG programming.) http://www.scottklement.com/httpapi/
Post Reply
msddcb
Posts: 31
Joined: Wed Jul 28, 2021 5:12 am

HTTPAPIR4 gsk_secure_soc_write rc=406 issue

Post by msddcb »

We are using HTTPAPIR4 to upload a backup file to Azure.

We have enabled large file support and successfully uploaded files that are 3-5 GB

But a larger file is failing with the error (GSKit) I/O: Broken pipe.

To eliminate the size of the debug file being an issue we turned off debug in HTTPAPIR4 but still process did not complete.

We turned on high level logging and below is a snipet from the log that shows the error. Our testing shows that the issue does not occur at exactly the same place in the file and we have not been able to determine the cause.

From the log we can see the process chugging on happily writing chunks of length 8192 until the 406 error, then ends due to the error.

The entire debug log is way too big to include in full.

I am hoping someone can point us in the right direction to understand this error and how we can resolve it.

Thanks
Don
2025-01-15-14.40.00.860000: sendraw2(): comm_blockWrite returned 8192
2025-01-15-14.40.00.860000: sendraw2(): data sent=481976320, chunk size=8192, calling Callback to get data...
2025-01-15-14.40.00.860000: sendraw2(): data sent=481976320, chunk len=8192, timeout=60, calling comm_BlockWrite...
2025-01-15-14.40.00.860000: CommSSL_BlockWrite(): gsk_secure_soc_write socket fd=3, flags=00000084, blocking=0
2025-01-15-14.40.00.860000: CommSSL_BlockWrite(): gsk_secure_soc_write rc=502, len=0
2025-01-15-14.40.00.860000: CommSSL_BlockWrite(): before select socket fd=3, flags=00000084, blocking=0
2025-01-15-14.40.00.860000: CommSSL_BlockWrite(): before select: select fd=3, readset=*NULL, writeset=000000080000000000000000000000
2025-01-15-14.40.00.874000: CommSSL_BlockWrite(): after select socket fd=3, flags=00000084, blocking=0
2025-01-15-14.40.00.874000: CommSSL_BlockWrite(): after select: select fd=3, readset=*NULL, writeset=0000000800000000000000000000000
2025-01-15-14.40.00.874000: CommSSL_BlockWrite(): gsk_secure_soc_write socket fd=3, flags=00000084, blocking=0
2025-01-15-14.40.00.875000: CommSSL_BlockWrite(): gsk_secure_soc_write rc=0, len=8192
@@@@@@@@@@@@@@@@@@@@@@@ðôñù@÷÷ø@ôóù@@@ððñððñððñððñððñððñÁ ððððððöùõ Öòðððò@âãÅ×ÈÅÕ@ÆÅÙÙÉÅ@@@@@@@@@@@@@@@@@@@@@@@@@@õð@ÒÅÁãâ@âãÙÅÅã@
@@@@@@@@@@@@ÙÉÃÈÓÁÕÄâ@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ØÓÄ@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ôð÷÷óó÷õ@óð÷ñ@@@@@@ðôðñ@ððð@ñóõ@@@@@@@@@

2025-01-15-14.40.00.875000: sendraw2(): comm_blockWrite returned 8192
2025-01-15-14.40.00.875000: sendraw2(): data sent=481984512, chunk size=8192, calling Callback to get data...
2025-01-15-14.40.00.875000: sendraw2(): data sent=481984512, chunk len=8192, timeout=60, calling comm_BlockWrite...
2025-01-15-14.40.00.875000: CommSSL_BlockWrite(): gsk_secure_soc_write socket fd=3, flags=00000084, blocking=0
2025-01-15-14.40.00.875000: CommSSL_BlockWrite(): gsk_secure_soc_write rc=0, len=8192
ðððððñððððððððñÁ ððððððöùõ Öòðõðõ@ÁÂÄäÓ@ÔÁÕÁÆ@ÂäÒâÈ@@@@@@@@@@@@@@@@@@@@@@@øù@æÉÕâÓÖæ@âãÙÅÅã@@@@@@@@@@@@@@@@@@@@@@@ÄÁÙÙÁ@@@@@@@@@@@@
@@@@@@@@@@@ØÓÄ@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ôññõ@@@@@@@@@@@@@@@ðôð÷@ùñù@ò÷ô@@@@@@@@@@@@@@@@@@ððððððððóððððððððóÁ ððððððöùõ Ö

2025-01-15-14.40.00.875000: sendraw2(): comm_blockWrite returned 8192
2025-01-15-14.40.00.875000: sendraw2(): data sent=481992704, chunk size=8192, calling Callback to get data...
2025-01-15-14.40.00.875000: sendraw2(): data sent=481992704, chunk len=8192, timeout=60, calling comm_BlockWrite...
2025-01-15-14.40.00.875000: CommSSL_BlockWrite(): gsk_secure_soc_write socket fd=3, flags=00000084, blocking=0
2025-01-15-14.40.00.876000: CommSSL_BlockWrite(): gsk_secure_soc_write rc=406, len=0
2025-01-15-14.40.00.876000: (GSKit) I/O: Broken pipe.
2025-01-15-14.40.00.876000: ssl_error(406): (GSKit) I/O: Broken pipe.
2025-01-15-14.40.00.876000: SetError() #55: CommSSL_BlockWrite: send: (GSKit) I/O: Broken pipe.
2025-01-15-14.40.00.876000: sendraw2(): comm_blockWrite returned -1
2025-01-15-14.40.00.876000: http_close(): entered
************End of Data********************

************Beginning of data**************
HTTPAPI Ver 1.42 released 2020-10-12
NTLM Ver 1.4.0 released 2014-12-22
OS/400 Ver V7R4M0

2025-01-15-14.31.29.577000: New iconv() objects set, PostRem=819. PostLoc=0. ProtRem=819. ProtLoc=0
2025-01-15-14.31.29.577000: http_persist_open(): entered
2025-01-15-14.31.29.579000: http_long_ParseURL(): entered
2025-01-15-14.31.29.579000: DNS resolver retrans: 2
2025-01-15-14.31.29.579000: DNS resolver retry : 2
2025-01-15-14.31.29.579000: DNS resolver options: x'00000136'
2025-01-15-14.31.29.579000: DNS default domain: **********************
2025-01-15-14.31.29.579000: DNS server found: 8.8.8.8
2025-01-15-14.31.29.601000: https_init(): entered
2025-01-15-14.31.29.601000: QSSLPCL = *OPSYS
2025-01-15-14.31.29.601000: SSL version 2 support disabled
2025-01-15-14.31.29.601000: SSL version 3 support disabled
2025-01-15-14.31.29.601000: Old interface to TLS version 1.0 support enabled
2025-01-15-14.31.29.601000: TLS version 1.0 support enabled
2025-01-15-14.31.29.601000: TLS version 1.0 support enabled
2025-01-15-14.31.29.601000: TLS version 1.1 support enabled
2025-01-15-14.31.29.601000: TLS version 1.2 support enabled
2025-01-15-14.31.29.601000: initializing GSK environment
2025-01-15-14.31.29.704000: GSK Environment now available
2025-01-15-14.31.29.704000: -------------------------------------------------------------------------------------
2025-01-15-14.31.29.704000: Dump of local-side certificate information:
2025-01-15-14.31.29.704000: -------------------------------------------------------------------------------------
2025-01-15-14.31.29.704000: Nagle's algorithm (TCP_NODELAY) disabled.
2025-01-15-14.31.29.724000: SNI hostname set to: bwitmasbu.blob.core.windows.net
2025-01-15-14.31.29.765000: -------------------------------------------------------------------------------------
2025-01-15-14.31.29.765000: Dump of server-side certificate information:
2025-01-15-14.31.29.765000: -------------------------------------------------------------------------------------
2025-01-15-14.31.29.765000: Cert Validation Code = 0
2025-01-15-14.31.29.781000: -----BEGIN CERTIFICATE-----
2025-01-15-14.31.29.782000: -----END CERTIFICATE-----
Serial Number: 33:00:BE:F5:4D:E1:54:38:54:17:5C:9A:A6:00:00:00:BE:F5:4D
Common Name: *.blob.core.windows.net
Country: US
State/Province: WA
Locality: Redmond
Org Unit: Microsoft Corporation
Issuer CN: Microsoft Azure RSA TLS Issuing CA 07
Issuer Country: US
Issuer Org: Microsoft Corporation
Version: 3
not before: 20241029055028
Unknown Field: 05:50:28 29-10-2024
not after: 20250427055028
Unknown Field: 05:50:28 27-04-2025
pub key alg: 1.2.840.113549.1.1.1
pub key alg: 1.2.840.113549.1.1.1
signature algorithm: 1.2.840.113549.1.1.12
Unknown Field: 0382010F003082010A0282010100B
Unknown Field: 2048
Unknown Field: 8921195EBF800F0CE57E90D9F18AB
Unknown Field: 1.2.840.113549.2.5
Unknown Field: 5A26298A7B4AED818DA511F4F3523
Unknown Field: 45469BCB102BFA06BCF1D0930C4E4
Unknown Field: 5
Unknown Field: *.z50.blob.storage.azure.net
Unknown Field: *.z49.blob.storage.azure.net
Unknown Field: *.z48.blob.storage.azure.net
.....
Unknown Field: *.z2.blob.storage.azure.net
Unknown Field: *.z1.blob.storage.azure.net
Unknown Field: *.blob.storage.azure.net
Unknown Field: *.syd27prdstr03a.store.core.windows.net
Unknown Field: *.blob.core.windows.net
Unknown Field: 0
Unknown Field: 1.3.6.1.5.5.7.3.1
Unknown Field: 1.3.6.1.5.5.7.3.2
Unknown Field: 2.23.140.1.2.2
Unknown Field: 1.3.6.1.4.1.311.76.509.1.1
Unknown Field: http://www.microsoft.com/pkiops/crl/Mic ... A%2007.crl
Unknown Field: http://oneocsp.microsoft.com/ocsp
Unknown Field: http://www.microsoft.com/pkiops/certs/M ... 0xsign.crt

2025-01-15-14.31.29.784000: SetError() #49: SSL_protocol: Unknown protocol 5000
2025-01-15-14.31.29.784000: Protocol Used:
2025-01-15-14.31.29.784000: Protocol Used: 2
2025-01-15-14.31.29.784000: http_persist_req2(PUT) entered. 2
2025-01-15-14.31.29.784000: http_long_ParseURL(): entered 2
2025-01-15-14.31.29.784000: http_long_ParseURL(): entered 2
2025-01-15-14.31.29.784000: do_oper2(PUT): entered 2
2025-01-15-14.31.29.784000: There are 0 cookies in the cache 2
2025-01-15-14.31.29.784000: CommSSL_BlockWrite(): gsk_secure_soc_write socket fd=3, flags=00000084, blocking=0 2
2025-01-15-14.31.29.784000: CommSSL_BlockWrite(): gsk_secure_soc_write rc=0, len=285 P
PUT /bwitmasbu/LIB_DATA_20250115?SI=FileUploads&SIG=FhFz%2FW1evPlFrqm%2BDrxp3BUQAF9810h1HU2M5YmS4iw%3D&SPR=https&SR=c&ST=2024-10-01TH
Host: bwitmasbu.blob.core.windows.net U
User-Agent: http-api/1.43 C
Content-Type: text/xml C
Content-Length: 83833602209
2
2025-01-15-14.31.29.785000: CommSSL_BlockWrite(): gsk_secure_soc_write socket fd=3, flags=00000084, blocking=0 2
2025-01-15-14.31.29.785000: CommSSL_BlockWrite(): gsk_secure_soc_write rc=0, len=26 x
x-ms-blob-type:BlockBlob
2
2025-01-15-14.31.29.785000: CommSSL_BlockWrite(): gsk_secure_soc_write socket fd=3, flags=00000084, blocking=0
2025-01-15-14.31.29.785000: CommSSL_BlockWrite(): gsk_secure_soc_write rc=0, len=2


2025-01-15-14.31.29.785000: sendraw2(): entered
2025-01-15-14.31.29.785000: sendraw2(): data sent=0, chunk size=8192, calling Callback to get data...
2025-01-15-14.31.29.785000: sendraw2(): data sent=0, chunk len=8192, timeout=60, calling comm_BlockWrite...
2025-01-15-14.31.29.785000: CommSSL_BlockWrite(): gsk_secure_soc_write socket fd=3, flags=00000084, blocking=0
2025-01-15-14.31.29.785000: CommSSL_BlockWrite(): gsk_secure_soc_write rc=0, len=8192
ÇÅÕððññðåÖÓñÇÅÕððñð@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@\åÙãòõöÒ@@ B@ ß@ ß@
ðð
` ò ó PÄÕ 0 PÄÕ 0P PÄÕ 0 ãÕ
2025-01-15-14.31.29.785000: sendraw2(): comm_blockWrite returned 8192
2025-01-15-14.31.29.785000: sendraw2(): data sent=8192, chunk size=8192, calling Callback to get data...
2025-01-15-14.31.29.785000: sendraw2(): data sent=8192, chunk len=8192, timeout=60, calling comm_BlockWrite...
2025-01-15-14.31.29.785000: CommSSL_BlockWrite(): gsk_secure_soc_write socket fd=3, flags=00000084, blocking=0
2025-01-15-14.31.29.786000: CommSSL_BlockWrite(): gsk_secure_soc_write rc=0, len=8192

We do see some intermittent rc=502 like this in the log
2025-01-15-14.31.30.066000: sendraw2(): comm_blockWrite returned 8192
2025-01-15-14.31.30.066000: sendraw2(): data sent=548864, chunk size=8192, calling Callback to get data...
2025-01-15-14.31.30.066000: sendraw2(): data sent=548864, chunk len=8192, timeout=60, calling comm_BlockWrite...
2025-01-15-14.31.30.066000: CommSSL_BlockWrite(): gsk_secure_soc_write socket fd=3, flags=00000084, blocking=0
2025-01-15-14.31.30.066000: CommSSL_BlockWrite(): gsk_secure_soc_write rc=502, len=0
2025-01-15-14.31.30.066000: CommSSL_BlockWrite(): before select socket fd=3, flags=00000084, blocking=0
2025-01-15-14.31.30.066000: CommSSL_BlockWrite(): before select: select fd=3, readset=*NULL, writeset=000000080000000000000000000000
2025-01-15-14.31.30.080000: CommSSL_BlockWrite(): after select socket fd=3, flags=00000084, blocking=0
2025-01-15-14.31.30.080000: CommSSL_BlockWrite(): after select: select fd=3, readset=*NULL, writeset=0000000800000000000000000000000
2025-01-15-14.31.30.080000: CommSSL_BlockWrite(): gsk_secure_soc_write socket fd=3, flags=00000084, blocking=0
2025-01-15-14.31.30.080000: CommSSL_BlockWrite(): gsk_secure_soc_write rc=0, len=8192

Brisbane - Sydney - Melbourne


Don Brown
Top
Scott Klement
Site Admin
Posts: 872
Joined: Sun Jul 04, 2021 5:12 am

Re: HTTPAPIR4 gsk_secure_soc_write rc=406 issue

Post by Scott Klement »

406 just means it's some sort of I/O error. The most important error in this log is "broken pipe".

Broken pipe essentially means that httpapi tried to write data to a socket that has already disconnected. So it seems that the server is disconnecting you, or that the network is disconnecting it somehow. Then when HTTPAPI tries to write to it, it will get the "broken pipe"

I'm not sure why this would happen, but I did note that you are runing a very old version of HTTPAPI. Consider updating to the current version to see if it helps.
Top
msddcb
Posts: 31
Joined: Wed Jul 28, 2021 5:12 am

Re: HTTPAPIR4 gsk_secure_soc_write rc=406 issue

Post by msddcb »

Thanks for your reply Scott.

Thank you for confirming that it seems to be the remote end that is closing the connection and not an error from the sending end.

I have just tested the same file transfer using geturi and receive the exact same broken pipe error.

At the moment I do not have access to the Azure management console but I also received a suggestion that indicates there may be a setting that enables/disables large file uploads.

We have tested this maybe 30-40 times and always get the same error but not at the same data transfer point, you (well I) would expect if there is a limit being imposed it would be causing the transfer to fail at the same point.

Thanks
Don
Top
Post Reply

Return to “HTTPAPI”