bug#32658: gnutls + non-blocking url-retrieve

[thomas@m3y3r.de]

thomas@m3y3r.de writes:

> Eli Zaretskii <eliz@gnu.org> writes:
>
>>> From: thomas@m3y3r.de
>>> Date: Sun, 30 Sep 2018 23:33:10 +0200
>>> 
>>> 1.) I needed to revert to gnutls 3.5.19, the mingw64 build from the
>>> gitlab ci build seems to have a working gnutls-cli tools on windows 10.
>>> the gitlab builds for 3.6.3 and 3.6.4 seems to have another bug
>>> (error code -53) in the gnutls-cli command.
>>> 
>>> so only gnutls 3.5.19 have a working gnutls-cli. i installed this version in emacs 26.1
>>> 
>>> 2.) testing gnutls stream
>>> using open-gnutls-stream directly gives me a correct tls connection but
>>> eww still fails to load the site.
>>> 
>>> when I change url-open-stream in url/url-gw.el to:
>>> 			  (open-network-stream
>>> 			   name buffer host service
>>> 			   :type gw-method
>>> 			   ;; Use non-blocking socket if we can.
>>>                           :nowait nil))
>>> 
>>> I finally can open lwn.net in eww.
>>> 
>>> so something seems to be wrong possible with blocking/non-blocking
>>> network access.
>>> 
>>> any ideas?
>>
>> Thanks for the info.
>

okay, some more infos.

I was able to bootstrap the emacs compile with mingw64.

while I was trying to debug this problem with fprintf, eww suddenly
started to work!!

It started to work after I did insert an fprintf after the
gnutls_try_handshake call in process.c !!

what is going on here?

diff --git a/src/gnutls.c b/src/gnutls.c
index 9e105b948f..374dfeb6e5 100644
--- a/src/gnutls.c
+++ b/src/gnutls.c
@@ -583,6 +583,7 @@ gnutls_try_handshake (struct Lisp_Process *proc)
 {
   gnutls_session_t state = proc->gnutls_state;
   int ret;
+  bool non_fatal;
   bool non_blocking = proc->is_non_blocking_client;
 
   if (proc->gnutls_complete_negotiation_p)
@@ -594,11 +595,11 @@ gnutls_try_handshake (struct Lisp_Process *proc)
   do
     {
       ret = gnutls_handshake (state);
-      emacs_gnutls_handle_error (state, ret);
+      non_fatal = emacs_gnutls_handle_error (state, ret);
       maybe_quit ();
     }
   while (ret < 0
-	 && gnutls_error_is_fatal (ret) == 0
+	 &&   non_fatal
 	 && ! non_blocking);
 
   proc->gnutls_initstage = GNUTLS_STAGE_HANDSHAKE_TRIED;
@@ -779,7 +780,7 @@ emacs_gnutls_handle_error (gnutls_session_t session, int err)
 
   /* TODO: use a Lisp_Object generated by gnutls_make_error?  */
   if (err >= 0)
-    return 1;
+    return true;
 
   check_memory_full (err);
 
diff --git a/src/process.c b/src/process.c
index b0a327229c..5bdb74868c 100644
--- a/src/process.c
+++ b/src/process.c
@@ -899,6 +899,10 @@ static void
 remove_process (register Lisp_Object proc)
 {
   register Lisp_Object pair;
+  struct Lisp_Process *lp = XPROCESS(proc);
+
+  fprintf (stderr, "DEBUG: remove process called for proc %s ", SDATA(lp->name) /*, status_message(&lp->status) */);
+  fprintf (stderr, "gnutls_initstage: %u\n", lp->gnutls_initstage);
 
   pair = Frassq (proc, Vprocess_alist);
   Vprocess_alist = Fdelq (pair, Vprocess_alist);
@@ -3283,6 +3287,8 @@ finish_after_tls_connection (Lisp_Object proc)
   Lisp_Object contact = p->childp;
   Lisp_Object result = Qt;
 
+  add_to_log("DEBUG: finish_after_tls_connection");
+
   if (!NILP (Ffboundp (Qnsm_verify_connection)))
     result = call3 (Qnsm_verify_connection,
 		    proc,
@@ -5097,9 +5103,12 @@ wait_reading_process_output (intmax_t time_limit, int nsecs, int read_kbd,
 		if (p->gnutls_initstage == GNUTLS_STAGE_HANDSHAKE_TRIED
 		    && p->is_non_blocking_client)
 		  {
-		    gnutls_try_handshake (p);
+		    fprintf (stderr, "DEBUG: trying_gnutls_handshake: %s, %lld, %d, %d, %d\n", SDATA(p->name), time_limit, nsecs, read_kbd, do_display);
+		    int rcgt = gnutls_try_handshake (p);
 		    p->gnutls_handshakes_tried++;
 
+		    fprintf (stderr, "DEBUG: after gnutls_handshake: %d, %d, %u\n", rcgt, p->gnutls_handshakes_tried, p->gnutls_initstage);
+
 		    if (p->gnutls_initstage == GNUTLS_STAGE_READY)
 		      {
 			gnutls_verify_boot (aproc, Qnil);

Here the output of stderr:

DEBUG: trying_gnutls_handshake: lwn.net<1>, 1, 843955000, -1, 1
DEBUG: after gnutls_handshake: -28, 1, 8
DEBUG: trying_gnutls_handshake: lwn.net<1>, 1, 650501000, -1, 1
DEBUG: after gnutls_handshake: -28, 2, 8
DEBUG: trying_gnutls_handshake: lwn.net<1>, 1, 650501000, -1, 1
DEBUG: after gnutls_handshake: -28, 3, 8
DEBUG: trying_gnutls_handshake: lwn.net<1>, 1, 650501000, -1, 1
DEBUG: after gnutls_handshake: -28, 4, 8
DEBUG: trying_gnutls_handshake: lwn.net<1>, 1, 650501000, -1, 1
DEBUG: after gnutls_handshake: -28, 5, 8
DEBUG: trying_gnutls_handshake: lwn.net<1>, 1, 650501000, -1, 1
DEBUG: after gnutls_handshake: -28, 6, 8
DEBUG: trying_gnutls_handshake: lwn.net<1>, 1, 650501000, -1, 1
DEBUG: after gnutls_handshake: -28, 7, 8
DEBUG: trying_gnutls_handshake: lwn.net<1>, 1, 650501000, -1, 1
DEBUG: after gnutls_handshake: 0, 8, 9
DEBUG: remove process called for proc lwn.net gnutls_initstage: 0
DEBUG: remove process called for proc lwn.net<1> gnutls_initstage: 3
DEBUG: trying_gnutls_handshake: lwn.net, 30, 0, -1, 1
DEBUG: after gnutls_handshake: -28, 1, 8
DEBUG: trying_gnutls_handshake: lwn.net, 30, 0, -1, 1
DEBUG: after gnutls_handshake: -28, 2, 8
DEBUG: trying_gnutls_handshake: lwn.net, 30, 0, -1, 1
DEBUG: after gnutls_handshake: -28, 3, 8
DEBUG: trying_gnutls_handshake: lwn.net, 30, 0, -1, 1
DEBUG: after gnutls_handshake: -28, 4, 8
DEBUG: trying_gnutls_handshake: lwn.net, 30, 0, -1, 1
DEBUG: after gnutls_handshake: -28, 5, 8
DEBUG: trying_gnutls_handshake: lwn.net, 30, 0, -1, 1
DEBUG: after gnutls_handshake: -28, 6, 8
DEBUG: trying_gnutls_handshake: lwn.net, 30, 0, -1, 1
DEBUG: after gnutls_handshake: -28, 7, 8
DEBUG: trying_gnutls_handshake: lwn.net, 30, 0, -1, 1
DEBUG: after gnutls_handshake: -28, 8, 8
DEBUG: trying_gnutls_handshake: lwn.net, 30, 0, -1, 1
DEBUG: after gnutls_handshake: 0, 9, 9
DEBUG: remove process called for proc lwn.net gnutls_initstage: 3

maybe this problem seems to be an timing and/or cpu issue? my laptop uses an
relativley new intel core i7-7500u cpu.