warmcat / libwebsockets

canonical libwebsockets.org networking library
https://libwebsockets.org
Other
4.73k stars 1.48k forks source link

Can't listen Server response. [FIN, ACK] sent after a write. No TLS. #1615

Closed fusionJose closed 5 years ago

fusionJose commented 5 years ago

Hi, I wrote a client copied from minimal-ws-client-rx, but disabling SSL (TLS)

image

And transmiting an initial messege when I get connected to server:

image

But I found sniffing in the network that 1,5 miliseconds later of sending the message it sends a [FIN, ACK]:

image

So the server doesn't response to my client.

This doesn't happen in the minimal examples because they work with TLS:

image

Here is the code:

`/*

include

include

include

include

include

include

static int bExit; static int interrupted, rx_seen, test; static struct lws *client_wsi; static char ping[LWS_PRE + 250];

static int callback_dumb_increment(struct lws wsi, enum lws_callback_reasons reason, void user, void *in, size_t len) {

    int n;

    json_object *jarray = json_object_new_array();
    json_object *jobj_type = json_object_new_object();
    json_object *jobj_ID = json_object_new_object();
    json_object *jobj_action = json_object_new_object();
    json_object *jobj = json_object_new_object();

    jobj_type = json_object_new_int(2); /* A call from client to server */

    jobj_ID = json_object_new_string("1946577");
    jobj_action = json_object_new_string("BootNotification");

    char *str = "{\
            \"chargePointVendor\": \"MilHouse\", \
            \"chargePointModel\": \"Fusion\", \
        }";

    //printf("str:\n---\n%s\n---\n\n", str);

    json_object_array_add(jarray,jobj_type);
    json_object_array_add(jarray,jobj_ID);
    json_object_array_add(jarray,jobj_action);

    jobj = json_tokener_parse(str);

    json_object_array_add(jarray,jobj);
    switch (reason) {

    /* because we are protocols[0] ... */
    case LWS_CALLBACK_CLIENT_CONNECTION_ERROR:
        lwsl_err("CLIENT_CONNECTION_ERROR: %s\n",
                 in ? (char *)in : "(null)");
        client_wsi = NULL;
        break;

    case LWS_CALLBACK_CLIENT_ESTABLISHED:
        lwsl_user("%s: established\n", __func__);
        lws_callback_on_writable(wsi);
        break;

    case LWS_CALLBACK_CLIENT_WRITEABLE:
        printf("[Test Protocol] The client is able to write.\n");

        // Write the buffer from the LWS_PRE index + 128 (the buffer size)

        int m;

        printf("jobj from str:\n---\n%s\n---\n", json_object_to_json_string_ext(jarray, JSON_C_TO_STRING_PLAIN));

        n = 0;

        n = snprintf((char *)ping + LWS_PRE, json_object_array_length(jarray),
            json_object_to_json_string_ext(jarray, JSON_C_TO_STRING_PLAIN));

        sprintf((char *)ping + LWS_PRE, json_object_to_json_string_ext(jarray, JSON_C_TO_STRING_PLAIN));

        lwsl_user("Sending PING %d...\n", n);

        m = lws_write(wsi, ping + LWS_PRE, n, LWS_WRITE_TEXT);
        if (m < n) {
            lwsl_err("sending ping failed: %d\n", m);
        }

        lws_callback_on_writable(wsi);
        break;

    case LWS_CALLBACK_CLIENT_RECEIVE:
            lwsl_user("RX: %s\n", (const char *)in);
            rx_seen++;
            if (test && rx_seen == 10)
                    interrupted = 1;
            break;

    case LWS_CALLBACK_CLIENT_CLOSED:
            client_wsi = NULL;
            break;

    default:
            break;
    }

    return lws_callback_http_dummy(wsi, reason, user, in, len);

}

static const struct lws_protocols protocols[] = { { "ocpp1.6", callback_dumb_increment, 0, 0, }, { NULL, NULL, 0, 0 } };

static void sigint_handler(int sig) { interrupted = 1; }

int main(int argc, const char *argv) { struct lws_context_creation_info info; struct lws_client_connect_info i; struct lws_context context; const char p; int n = 0, logs = LLL_USER | LLL_ERR | LLL_WARN | LLL_NOTICE / for LLL_ verbosity above NOTICE to be built into lws, lws

Any idea?

Thank you.

fusionJose commented 5 years ago

Here is everything I could see in the network, until the [FIN, ACK], also SSH communication with my app:

image

lws-team commented 5 years ago

I'm not going to look at your code.

What about logs from lws?

fusionJose commented 5 years ago

Logs look like this:

image

I´m using QMAKE and I've configured he log level with all the flags:

image

Is there anything more that I can see?

Thanks.

lws-team commented 5 years ago

Did you build with cmake having -DCMAKE_BUILD_TYPE=DEBUG?

fusionJose commented 5 years ago

I'm using qmake, is there any way to build it with it? If not I will install the cmake. Thank you

lws-team commented 5 years ago

You can use what you want, it's foss.

But it's a bit brave just using qmake without referencing what cmake produces. You should at least follow the supported cmake flow and then do the make with V=1 VERBOSE=1 and see what the gcc commandline looks like.

And it's a bit presumptious dragging me along for the ride when you hit problems. Nobody said this works with qmake.

fusionJose commented 5 years ago

I´ve made the project with cmake, and still works the same. I´ve read the log and sais this:

' 0x0A (role=0x10000000) wsi->lextable_pos=238 [2019/06/25 10:54:11:6367] PARSER: known hdr 8 [2019/06/25 10:54:11:6367] PARSER: v00 hdrs done [2019/06/25 10:54:11:6368] PARSER: lws_client_int_s_hs: protocol list 'ocpp1.6' [2019/06/25 10:54:11:6368] DEBUG: Selected protocol ocpp1.6 [2019/06/25 10:54:11:6368] DEBUG: lws_ensure_user_space: 0x9007428 protocol pss 0, user_space=(nil) [2019/06/25 10:54:11:6368] DEBUG: lws_set_timeout: 0x9007428: 0 secs (reason 0) [2019/06/25 10:54:11:6368] INFO: lws_header_table_detach: wsi 0x9007428: ah 0x90084a8 (tsi=0, count = 1) [2019/06/25 10:54:11:6368] INFO: lws_header_table_detach: nobody usable waiting [2019/06/25 10:54:11:6368] INFO: _lws_destroy_ah: freed ah 0x90084a8 : pool length 0 [2019/06/25 10:54:11:6369] INFO: lws_header_table_detach: wsi 0x9007428: ah 0x90084a8 (tsi=0, count = 0) [2019/06/25 10:54:11:6369] DEBUG: lws_role_transition: 0x9007428: wsistate 0x10000117, ops ws [2019/06/25 10:54:11:6369] DEBUG: _realloc: size 4116: client frame buffer [2019/06/25 10:54:11:6369] INFO: Allocating client RX buffer 4112 [2019/06/25 10:54:11:6369] DEBUG: handshake OK for protocol ocpp1.6 [2019/06/25 10:54:11:6369] USER: callback_dumb_increment: established [2019/06/25 10:54:11:6369] DEBUG: _lws_change_pollfd: wsi 0x9007428: fd 6 events 1 -> 5 [2019/06/25 10:54:11:6370] DEBUG: _lws_change_pollfd: wsi 0x9007428: fd 6 events 5 -> 1 [2019/06/25 10:54:11:6370] DEBUG: lws_handle_POLLOUT_event: 0x9007428: non mux: wsistate 0x10000117, ops ws [Test Protocol] The client is able to write. jobj from str:

[2,"1946577","BootNotification",{"chargePointVendor":"MilHouse","chargePointModel":"Fusion"}]

[2019/06/25 10:54:11:6371] USER: Sending PING 93... [2019/06/25 10:54:11:6371] INFO: lws_issue_raw: ssl_capable_write (99) says 99 [2019/06/25 10:54:11:6373] INFO: rops_handle_POLLIN_ws: LWS_SSL_CAPABLE_ERROR [2019/06/25 10:54:11:6373] DEBUG: 0x9007428: Close and handled [2019/06/25 10:54:11:6373] INFO: lws_close_free_wsi: 0x9007428: caller: close_and_handled [2019/06/25 10:54:11:6373] DEBUG: __lws_close_free_wsi: real just_kill_connection: 0x9007428 (sockfd 6) [2019/06/25 10:54:11:6374] DEBUG: lwsi_set_state(0x9007428, 0x1000001e) [2019/06/25 10:54:11:6374] DEBUG: lws_close_free_wsi_final: wsi 0x9007428: fd 6 [2019/06/25 10:54:11:6374] INFO: lws_vhost_unbind_wsi: vh default: count_bound_wsi 0 [2019/06/25 10:54:11:6374] DEBUG: __lws_free_wsi: 0x9007428, remaining wsi 1 [2019/06/25 10:54:12:0409] DEBUG: _realloc: size 380: cbwsi [2019/06/25 10:54:12:0410] DEBUG: _realloc: size 24: cbtmr [2019/06/25 10:54:12:0410] DEBUG: lws_service_periodic_checks: timed cb: vh default, protocol lws-abs-cli-raw-skt, reason 1000

So it seems that after writing and sending the message it closes the socket. It calls to lws_close_free_wsi.

lws-team commented 5 years ago

So it seems that after writing and sending the message it closes the socket. It calls to lws_close_free_wsi.

No... after sending it sees the socket had been closed by the remote peer.

So have a look at his logs.

fusionJose commented 5 years ago

Okey, but I don't understand the LWS_SSL_CAPABLE_ERROR issue. I have SSL disabled.

lws-team commented 5 years ago

Openssl, mbedtls and no ssl all have their errors summarized into the same enum. Ssl-capable means it's an api that works the same (and produces the same internal error codes) whether its operating inside tls or not.

fusionJose commented 5 years ago

Of course the remote peer was closing.

I also noticed that the websocket client is sending in the HTTP header a Connection: close, upgrade, instead of only Connection: upgrade.

Is there anyway to change or configure the HTTP header? I saw in the libwebsockets code that comes from here:

if (!wsi->client_pipeline) conn1 = "close, "; p = lws_generate_client_ws_handshake(wsi, p, conn1);

Thank you

lws-team commented 5 years ago

Connection: close, upgrade is perfectly correct.

If your server blows up with it, set the flag LCCSCF_PIPELINE on client creation info .ssl_connection.

fusionJose commented 5 years ago

Okey, now works correctly. Thank you very much for all.