SSL read() error while reading response from a POST request

[code-ghalib]

Hello, I am encountering a strange error and would like to know if the authors can help.

I am trying to get a token from an OAuth2 server using a POST request. This request succeeds using curl or a python implementation using the requests library.

But when I use Cohttp_lwt_unix.Client, while the status code is 200, the extraction of the `Stream from Cohttp_lwt.Body.t, using Cohttp_lwt.Body.to_string fails with this error:

SSL read() error: error:00000000:lib(0):func(0):reason(0)

The google brought me to this issue on the curl repo: curl/curl#1689

This suggests that it's a problem with the server - but the server works fine with curl and python and even returns a successful status code, so it makes me wonder whether this is something peculiar with the Cohttp implementation (specifically the Transfer* modules).

Unfortunately I do not have a way for you to replicate the error, but I'm hoping someone has seen this before or can spot an obvious cause of this error.

Thank you!

[mseri]

Which version of cohttp are you using?

If you install tls-lwt and run your code setting CONDUIT_TLS=native, does it fail? Is the error the same?

[code-ghalib]

Hi @mseri thanks for looking into it - I'm using cohttp 5.0.0. It's not easy for me to try tls-lwt unfortunately - internal system package manager (not opam) doesn't have tls-lwt and some of its dependencies, so I'd need to package those first. Is the SSL version officially not supported?

[mseri]

It is absolutely supported. I was asking to check if using a different stack was working, and if not hopefully get a more informative error. It is hard for me to debug this problem without knowing if the issue is in cohttp, conduit, lwt, the c bindings or somewhere else

[mseri]

Fwiw the only similar error that I know is #980 in that case the same suggestion helped pinpointing the issue

[code-ghalib]

Sorry @mseri for the delay in responding. I have tried to get you some more information to help identify the issue.

Here's the relevant snippet of the output of strace:

read(5, "\27\3\3\5R", 5)                = 5
read(5, "<redacted>"..., 1362) = 1362
read(5, "", 5)                          = 0
rt_sigaction(SIGSEGV, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7feee1632630}, NULL, 8) = 0
sigaltstack({ss_sp=NULL, ss_flags=SS_DISABLE, ss_size=140736435436216}, {ss_sp=0x26a7a80, ss_flags=0, ss_size=8192}) = 0
write(2, "Fatal error: exception OUnitTest"..., 108) = 108
exit_group(2)                           = ?
+++ exited with 2 +++

As you can see it's the 3rd read system call that's failing because it's expecting to read 5 bytes from an empty buffer (I think?), so likely a mis-calculation of the length of things somewhere.

The stack trace that leads to that system call (and also the others probably) is as follows:

read(5, "", 5)                          = 0
 > /usr/lib64/libpthread-2.17.so(read+0x2d) [0xe75d]
 > /tls-test/_build/default/test/main.exe(sock_read+0x34) [0xa7de14]
 > /tls-test/_build/default/test/main.exe(bread_conv+0x19) [0xa7c819]
 > /tls-test/_build/default/test/main.exe(BIO_read+0xa5) [0xa7b4f5]
 > /tls-test/_build/default/test/main.exe(ssl3_read_n+0x230) [0xa23a70]
 > /tls-test/_build/default/test/main.exe(ssl3_get_record+0x91) [0xa28291]
 > /tls-test/_build/default/test/main.exe(ssl3_read_bytes+0x133) [0xa25a93]
 > /tls-test/_build/default/test/main.exe(ssl3_read+0x5f) [0xa2c7bf]
 > /tls-test/_build/default/test/main.exe(SSL_read+0x14) [0xa363b4]
 > /tls-test/_build/default/test/main.exe(ocaml_ssl_read_into_bigarray+0xaf) [0xa2174f]
 > /tls-test/_build/default/test/main.exe(camlLwt_ssl__fun_1611+0x30) [0x89ae40]
 > /tls-test/_build/default/test/main.exe(camlLwt_ssl__wrap_call_686+0x21) [0x89a4a1]
 > /tls-test/_build/default/test/main.exe(camlLwt_ssl__fun_1527+0x29) [0x89a5e9]
 > /tls-test/_build/default/test/main.exe(camlLwt_io__perform_io_1167+0x167) [0x97fef7]
 > /tls-test/_build/default/test/main.exe(camlLwt_io__unsafe_read_into$27_1681+0xc9) [0x982329]
 > /tls-test/_build/default/test/main.exe(camlLwt_io__read_2011+0xc6) [0x982b76]
 > /tls-test/_build/default/test/main.exe(camlLwt__try_bind_1657+0x2d) [0x9aa7ad]
 > /tls-test/_build/default/test/main.exe(camlCohttp_lwt_unix__Io__fun_1359+0x58) [0x85ef58]
 > /tls-test/_build/default/test/main.exe(camlLwt__catch_1562+0x28) [0x9a9ec8]
 > /tls-test/_build/default/test/main.exe(camlCohttp__Transfer_io__read_534+0x52) [0x876b82]
 > /tls-test/_build/default/test/main.exe(camlCohttp_lwt__Body__fun_1090+0x68) [0x85fd28]
 > /tls-test/_build/default/test/main.exe(camlLwt_stream__feed_960+0x9f) [0x9b11df]
 > /tls-test/_build/default/test/main.exe(camlLwt_stream__iter_rec_1401+0x68) [0x9b3be8]
 > /tls-test/_build/default/test/main.exe(camlCohttp_lwt__Body__to_string_688+0xbd) [0x85ff6d]
 > /tls-test/_build/default/test/main.exe(camlHttp__fun_1344+0x4c) [0x85e7ac]
 > /tls-test/_build/default/test/main.exe(camlLwt__callback_1438+0xdf) [0x9a93cf]
 > /tls-test/_build/default/test/main.exe(camlLwt__iter_callback_list_1000+0x77) [0x9a8077]
 > /tls-test/_build/default/test/main.exe(camlLwt__run_in_resolution_loop_1070+0x24) [0x9a81e4]
 > /tls-test/_build/default/test/main.exe(camlLwt__resolve_1090+0x52) [0x9a8382]
 > /tls-test/_build/default/test/main.exe(camlLwt__callback_1438+0x146) [0x9a9436]
 > /tls-test/_build/default/test/main.exe(camlLwt__iter_callback_list_1000+0x77) [0x9a8077]
 > /tls-test/_build/default/test/main.exe(camlLwt__run_in_resolution_loop_1070+0x24) [0x9a81e4]
 > /tls-test/_build/default/test/main.exe(camlLwt__resolve_1090+0x52) [0x9a8382]
 > /tls-test/_build/default/test/main.exe(camlLwt__callback_1438+0x146) [0x9a9436]
 > /tls-test/_build/default/test/main.exe(camlLwt__iter_callback_list_1000+0x77) [0x9a8077]
 > /tls-test/_build/default/test/main.exe(camlLwt__run_in_resolution_loop_1070+0x24) [0x9a81e4]
 > /tls-test/_build/default/test/main.exe(camlLwt__resolve_1090+0x52) [0x9a8382]
 > /tls-test/_build/default/test/main.exe(camlLwt__callback_1438+0x146) [0x9a9436]
 > /tls-test/_build/default/test/main.exe(camlLwt__iter_callback_list_1000+0x77) [0x9a8077]
 > /tls-test/_build/default/test/main.exe(camlLwt__run_in_resolution_loop_1070+0x24) [0x9a81e4]
 > /tls-test/_build/default/test/main.exe(camlLwt__resolve_1090+0x52) [0x9a8382]
 > /tls-test/_build/default/test/main.exe(camlLwt__callback_1577+0x14d) [0x9aa23d]
 > /tls-test/_build/default/test/main.exe(camlLwt__iter_callback_list_1000+0x77) [0x9a8077]
 > /tls-test/_build/default/test/main.exe(camlLwt__run_in_resolution_loop_1070+0x24) [0x9a81e4]
 > /tls-test/_build/default/test/main.exe(camlLwt__resolve_1090+0x52) [0x9a8382]
 > /tls-test/_build/default/test/main.exe(camlLwt__callback_1438+0x146) [0x9a9436]
 > /tls-test/_build/default/test/main.exe(camlLwt__iter_callback_list_1000+0x77) [0x9a8077]
 > /tls-test/_build/default/test/main.exe(camlLwt__run_in_resolution_loop_1070+0x24) [0x9a81e4]
 > /tls-test/_build/default/test/main.exe(camlLwt__resolve_1090+0x52) [0x9a8382]
 > /tls-test/_build/default/test/main.exe(camlLwt__callback_1673+0x22e) [0x9aac9e]
 > /tls-test/_build/default/test/main.exe(camlLwt__iter_callback_list_1000+0x77) [0x9a8077]
 > /tls-test/_build/default/test/main.exe(camlLwt__run_in_resolution_loop_1070+0x24) [0x9a81e4]
 > /tls-test/_build/default/test/main.exe(camlLwt__resolve_1090+0x52) [0x9a8382]
 > /tls-test/_build/default/test/main.exe(camlLwt__callback_1577+0x14d) [0x9aa23d]
 > /tls-test/_build/default/test/main.exe(camlLwt__iter_callback_list_1000+0x77) [0x9a8077]
 > /tls-test/_build/default/test/main.exe(camlLwt__run_in_resolution_loop_1070+0x24) [0x9a81e4]
 > /tls-test/_build/default/test/main.exe(camlLwt__resolve_1090+0x52) [0x9a8382]
 > /tls-test/_build/default/test/main.exe(camlLwt__callback_1531+0x17c) [0x9a9d6c]
 > /tls-test/_build/default/test/main.exe(camlLwt__iter_callback_list_1000+0x77) [0x9a8077]
 > /tls-test/_build/default/test/main.exe(camlLwt__run_in_resolution_loop_1070+0x24) [0x9a81e4]
 > /tls-test/_build/default/test/main.exe(camlLwt__resolve_1090+0x52) [0x9a8382]
 > /tls-test/_build/default/test/main.exe(camlLwt__callback_1438+0x146) [0x9a9436]
 > /tls-test/_build/default/test/main.exe(camlLwt__iter_callback_list_1000+0x77) [0x9a8077]
 > /tls-test/_build/default/test/main.exe(camlLwt__run_in_resolution_loop_1070+0x24) [0x9a81e4]
 > /tls-test/_build/default/test/main.exe(camlLwt__resolve_1090+0x52) [0x9a8382]
 > /tls-test/_build/default/test/main.exe(camlLwt__callback_1438+0x146) [0x9a9436]
 > /tls-test/_build/default/test/main.exe(camlLwt__iter_callback_list_1000+0x77) [0x9a8077]
 > /tls-test/_build/default/test/main.exe(camlLwt__run_in_resolution_loop_1070+0x24) [0x9a81e4]
 > /tls-test/_build/default/test/main.exe(camlLwt__resolve_1090+0x52) [0x9a8382]
 > /tls-test/_build/default/test/main.exe(camlLwt__callback_1438+0x146) [0x9a9436]
 > /tls-test/_build/default/test/main.exe(camlLwt__iter_callback_list_1000+0x77) [0x9a8077]
 > /tls-test/_build/default/test/main.exe(camlLwt__run_in_resolution_loop_1070+0x24) [0x9a81e4]
 > /tls-test/_build/default/test/main.exe(camlLwt__resolve_1090+0x52) [0x9a8382]
 > /tls-test/_build/default/test/main.exe(camlLwt__callback_2228+0x49) [0x9ad739]
 > /tls-test/_build/default/test/main.exe(camlLwt__iter_callback_list_1000+0xbb) [0x9a80bb]
 > /tls-test/_build/default/test/main.exe(camlLwt__run_in_resolution_loop_1070+0x24) [0x9a81e4]
 > /tls-test/_build/default/test/main.exe(camlLwt__resolve_1090+0x52) [0x9a8382]
 > /tls-test/_build/default/test/main.exe(camlLwt__wakeup_general_1127+0xb1) [0x9a85d1]
 > /tls-test/_build/default/test/main.exe(camlLwt_sequence__loop_345+0x31) [0x9a6991]
 > /tls-test/_build/default/test/main.exe(caml_start_program+0x48) [0x12a8da4]
 > /tls-test/_build/default/test/main.exe(caml_callback_exn+0x1f) [0x129fd9f]
 > /tls-test/_build/default/test/main.exe(caml_callback+0x8) [0x129ff88]
 > /tls-test/_build/default/test/main.exe(ev_invoke_pending+0xc8) [0x127d39e]
 > /tls-test/_build/default/test/main.exe(lwt_libev_loop+0x34) [0x1270954]
 > /tls-test/_build/default/test/main.exe(camlLwt_engine__fun_2477+0x35) [0x972075]
 > /tls-test/_build/default/test/main.exe(camlLwt_main__run_loop_438+0x99) [0x975249]
 > /tls-test/_build/default/test/main.exe(camlLwt_main__run_496+0x10b) [0x9754db]
 > /tls-test/_build/default/test/main.exe(camlDune__exe__Main__entry+0x23) [0x849393]
 > /tls-test/_build/default/test/main.exe(caml_program+0x1038) [0x845fb8]
 > /tls-test/_build/default/test/main.exe(caml_start_program+0x48) [0x12a8da4]
 > /tls-test/_build/default/test/main.exe(caml_startup_common+0x21e) [0x128aa2e]
 > /tls-test/_build/default/test/main.exe(caml_startup+0x8) [0x128aa88]
 > /tls-test/_build/default/test/main.exe(main+0xb) [0x844e9b]

The "workaround" I'm using for now is to implement my own body_to_string as follows:

let body_to_string = function
  | #Cohttp.Body.t as body -> Lwt.return @@ Cohttp.Body.to_string body
  | `Stream s ->
    let s = Lwt_stream.wrap_exn s in
    let b = Buffer.create 1024 in
    let+ () =
      try
        Lwt_stream.iter
          (function
              | Ok x -> Buffer.add_string b x
              | Error e -> raise e )
          s
      with e ->
        Log.trace
          "Exception while processing http stream: %s"
          (Printexc.to_string e)
        |> Lwt.return
    in
    Buffer.contents b

Instead of the original implementation: https://github.com/mirage/ocaml-cohttp/blob/master/cohttp-lwt/src/body.ml#L45

This is unsatisfactory of course, as it masks an actual error by assuming it means "end of stream".

Please let me know if there's more debugging information I can collect for you. I am also trying to read through the source code of some of the packages involved to see if I can come up with a hypothesis - the C bindings looked pretty halal to me.

[mseri]

I could not see where we are miscalculating the size. So far I am suspecting that this is really an issue with the server (also because error 00000000, if I understood openssl documentation correctly, means no error).

I think python and curl are not failing because by default the ignore premature end of file errors, something that we cannot yet do in ocaml-ssl. If you can pin ocaml-ssl to a custom version and edit the code to set https://www.openssl.org/docs/manmaster/man3/SSL_CTX_set_options.html#SSL_OP_IGNORE_UNEXPECTED_EOF we could check if this resolves the issue

[code-ghalib]

Thanks @mseri - the size miscalculation is just speculation on my part. Your theory sounds a lot more plausible - I should be able to try a modified ocaml-ssl and report back to you in a couple of weeks as I'm currently away.

[code-ghalib]

Hi @mseri - sorry for the delay, I finally got some time to look into this. I used a modified version of ocaml-ssl and it did not work to fix the issue. But I'm not sure whether I set the option in the correct place. I set it immediately upon creation of the context, somewhere around here: https://github.com/savonet/ocaml-ssl/blob/master/src/ssl_stubs.c#L560

[mseri]

Seems like the correct place, but I would not bet on it, I don't know the innards of ocaml-ssl.