Ws_receive data given as string instead of json some of the time

I’m using: SWI-Prolog version 7.3.27

I created a meta interpreter that functions as a rule engine for an agent. The server is non-prolog and prolog connects to it with a websocket client and keep listening for messages from the server. Each message triggers the rule engine to run and send conclusions back to the server.

I receive messages from the server in json format so I added the format(json) option to the ws_receive. This seems to work fine most of the time. It receives the exact same message every time, but for some reason every third time the message is received as a string instead of parsed json dict.

I handle the receive

receive(WS, State, NewState) :-
    ws_receive(WS, Message, [ format(json) ]),
    websocket{ opcode: OpCode, data: Payload } :< Message,
    receive_message(OpCode, Payload, State, NewState, Response),
    send_response(WS, Response).

And this predicate check whether the message is really a string or not.

%%
%% Handle a message with the text opcode. 
%%
receive_text(in(Payload, State), out(none, State)) :- 
    string(Payload),
    !, debug(warn/connection, '[CONNECTION][WARN] message received is string instead of dict "~w" ...', [Payload]).
receive_text(in(Payload, State), out(Response, State)) :- 
    is_dict(Payload),
    _Key{ event: Event, dataType: DataType, data: Data } :< Payload,
    ...

The output below shows the debug log. An event is periodically send to the client form the server. Event “triggered” lines are successful runs, while the warn line failed. So the solver ran twice correctly and failed once. This keeps repeating.

% [CONNECTION] Calling solver for event "triggered" .
% [CONNECTION] Event "triggered" resulted in following actions: [action(say,0)].
% [CONNECTION] Calling solver for event "triggered" .
% [CONNECTION] Event "triggered" resulted in following actions: [action(say,0)].
% [CONNECTION][WARN] message received is string instead of dict "{"event":"triggered","data":"..." ...

Again this is in response to the exact same message. I am completely baffled.

Ralf

Seems odd. There is one log in the changelog:

commit b0411664eb841f70c9df1a20395555521b808421 (tag: V7.5.4)
Author: Jan Wielemaker <J.Wielemaker@cs.vu.nl>
Date:   Tue Apr 18 19:43:35 2017 +0200

    FIXED: Issue#84: ws_receive/3: fixed retry after an websocket
    `ping` message.

That would suggest an update (might be a good idea anyway). Next step is

?- debug(websocket).

which should print some messages. My next step would be

?- tspy(read_text_data/4).

that should get you to trace parsing the message, so you can see what is going on.

Ah. The upgrade did it. I feel so stupid.

Thanks!