Getting rasa to respond to socket.io messages

ella
(Michael Bell) #1

I am able to connect the rasa-webchat widget to rasa server and send messages, but rasa server doesn’t respond. I see this on the rasa server side:

2019-07-11 18:57:24 INFO engineio.server - 605b8c4958ed40c2a17a0e203e50d856: Received packet MESSAGE data 2[“user_uttered”,{“message”:“hello”,“customData”:{“userId”:“123”},“session_id”:“96f6cff69c08401f81f457dc796240e0”}] 2019-07-11 18:57:24 INFO socketio.server - received event “user_uttered” from 605b8c4958ed40c2a17a0e203e50d856 [/]

Then nothing is sent back.

I have configured credentials.yml with:

socketio: user_message_evt: user_utttered bot_message_evt: bot_uttered session_persistence: true

rasa: url: “http://localhost:5005/api

What am I missing?

(Ella Rohm-Ensing) #2

Can you show me what your rasa logs look like if you add the --debug flag to your rasa run command? It’s possible you’re not seeing a response because the bot is incorrectly predicting action_listen.

(Michael Bell) #3

Here is the log. Thanks.

2019-07-12 08:34:27 DEBUG    pykwalify.compat  - Using yaml library: 
/Users/mb/.local/share/virtualenvs/rasa-lBMJeIkC/lib/python3.6/site-packages/ruamel/yaml/__init__.py
2019-07-12 08:34:30 INFO     engineio.server  - 262f370d942649adbc485f98fab3ccf8: Sending packet OPEN data {'sid': '262f370d942649adbc485f98fab3ccf8', 'upgrades': ['websocket'], 'pingTimeout': 60000, 'pingInterval': 25000}
2019-07-12 08:34:30 DEBUG    rasa.core.channels.socketio  - User 262f370d942649adbc485f98fab3ccf8 connected to socketIO endpoint.
2019-07-12 08:34:30 INFO     engineio.server  - 262f370d942649adbc485f98fab3ccf8: Sending packet MESSAGE data 0
2019-07-12 08:34:30 INFO     engineio.server  - 262f370d942649adbc485f98fab3ccf8: Received packet MESSAGE data 2["session_request",{"session_id":"96f6cff69c08401f81f457dc796240e0"}]
2019-07-12 08:34:30 INFO     socketio.server  - received event "session_request" from 262f370d942649adbc485f98fab3ccf8 [/]
2019-07-12 08:34:30 INFO     socketio.server  - emitting event "session_confirm" to 262f370d942649adbc485f98fab3ccf8 [/]
2019-07-12 08:34:30 INFO     engineio.server  - 262f370d942649adbc485f98fab3ccf8: Sending packet MESSAGE data 2["session_confirm","96f6cff69c08401f81f457dc796240e0"]
2019-07-12 08:34:30 DEBUG    rasa.core.channels.socketio  - User 262f370d942649adbc485f98fab3ccf8 connected to socketIO endpoint.
2019-07-12 08:34:30 INFO     engineio.server  - 262f370d942649adbc485f98fab3ccf8: Received request to upgrade to websocket
2019-07-12 08:34:30 DEBUG    websockets.protocol  - undefined - state = CONNECTING
2019-07-12 08:34:30 DEBUG    websockets.protocol  - undefined - event = connection_made(<TCPTransport closed=False reading=True 0x7fdbafd43af8>)
2019-07-12 08:34:30 DEBUG    websockets.protocol  - undefined - state = OPEN
2019-07-12 08:34:30 DEBUG    websockets.protocol  - undefined < Frame(fin=True, opcode=1, data=b'2probe', rsv1=False, rsv2=False, rsv3=False)
2019-07-12 08:34:30 DEBUG    websockets.protocol  - undefined > Frame(fin=True, opcode=1, data=b'3probe', rsv1=False, rsv2=False, rsv3=False)
2019-07-12 08:34:30 DEBUG    websockets.protocol  - undefined < Frame(fin=True, opcode=1, data=b'5', rsv1=False, rsv2=False, rsv3=False)
2019-07-12 08:34:30 INFO     engineio.server  - 262f370d942649adbc485f98fab3ccf8: Upgrade to websocket successful
2019-07-12 08:34:40 DEBUG    websockets.protocol  - undefined < Frame(fin=True, opcode=1, data=b'42["user_uttered",{"message":"hello ","customData":{"userId":"123"},"session_id":"96f6cff69c08401f81f457dc796240e0"}]', rsv1=False, rsv2=False, rsv3=False)
2019-07-12 08:34:40 INFO     engineio.server  - 262f370d942649adbc485f98fab3ccf8: Received packet MESSAGE data 2["user_uttered",{"message":"hello ","customData":{"userId":"123"},"session_id":"96f6cff69c08401f81f457dc796240e0"}]
2019-07-12 08:34:40 INFO     socketio.server  - received event "user_uttered" from 262f370d942649adbc485f98fab3ccf8 [/]
(Ella Rohm-Ensing) #4

Hm this doesn’t seem to show any rasa debugging information though. Can you put everything on from the rasa run command? It should e.g. say something like

2019-07-12 17:52:49 DEBUG    rasa.model  - Extracted model to '/var/folders/h_/jnhnb5q137x0t5cfbv6cc9hr0000gp/T/tmpxbur1iev'.
2019-07-12 17:52:49 DEBUG    rasa.cli.utils  - Parameter 'endpoints' not set. Using default location 'endpoints.yml' instead.
2019-07-12 17:52:49 DEBUG    rasa.model  - Extracted model to '/var/folders/h_/jnhnb5q137x0t5cfbv6cc9hr0000gp/T/tmpz6anms29'.
2019-07-12 17:52:51 DEBUG    sanic.root  - CORS: Configuring CORS with resources: {'/*': {'origins': [''], 'methods': 'DELETE, GET, HEAD, OPTIONS, PATCH, POST, PUT', 'allow_headers': ['.*'], 'expose_headers': None, 'supports_credentials': False, 'max_age': None, 'send_wildcard': False, 'automatic_options': True, 'vary_header': True, 'resources': {'/*': {'origins': ''}}, 'intercept_exceptions': True, 'always_send': True}}
2019-07-12 17:52:51 DEBUG    rasa.core.utils  - Available web server routes:
/webhooks/rest                                     GET                            custom_webhook_CmdlineInput.health
/webhooks/rest/webhook                             POST                           custom_webhook_CmdlineInput.receive
2019-07-12 17:52:51 INFO     root  - Starting Rasa Core server on http://localhost:5005
2019-07-12 17:52:51 INFO     root  - Enabling coroutine debugging. Loop id 5338869784.
2019-07-12 17:52:51 DEBUG    rasa.model  - Extracted model to '/var/folders/h_/jnhnb5q137x0t5cfbv6cc9hr0000gp/T/tmp6t0abxdt'.
2019-07-12 17:52:52 DEBUG    rasa.core.tracker_store  - Connected to InMemoryTrackerStore.
2019-07-12 17:52:52 DEBUG    rasa.model  - Extracted model to '/var/folders/h_/jnhnb5q137x0t5cfbv6cc9hr0000gp/T/tmp4o_2tb09'.
2019-07-12 17:52:52 DEBUG    pykwalify.compat  - Using yaml library: /Users/ella/miniconda3/envs/rasa/lib/python3.7/site-packages/ruamel/yaml/__init__.py

Here I’m only seeing debug messages from the socket channel.

Also, do you have access to the HTTP requests hitting the rasa server on 5005? E.g. through the ngrok UI if you are using that?

(Michael Bell) #5

Sorry, here is full log:

(rasa) Michaels-MacBook-Pro:rasa mb$ rasa run  --enable-api --debug
2019-07-12 09:16:15 DEBUG    rasa.cli.utils  - Parameter 'endpoints' not set. Using default location 'endpoints.yml' instead.
2019-07-12 09:16:15 DEBUG    rasa.cli.utils  - Parameter 'credentials' not set. Using default location 'credentials.yml' instead.
2019-07-12 09:16:18 DEBUG    rasa.model  - Extracted model to '/var/folders/wk/ynmgx56s43xcfzq2cc3_nmw40000gn/T/tmp4jidna5o'.
2019-07-12 09:16:18 INFO     engineio.server  - Server initialized for sanic.
2019-07-12 09:16:18 DEBUG    rasa.core.utils  - Available web server routes: 
/conversations/<conversation_id>/messages          POST                           add_message
/conversations/<conversation_id>/tracker/events    POST                           append_events
/webhooks/rasa                                     GET                            custom_webhook_RasaChatInput.health
/webhooks/rasa/webhook                             POST                           custom_webhook_RasaChatInput.receive
/webhooks/rest                                     GET                            custom_webhook_RestInput.health
/webhooks/rest/webhook                             POST                           custom_webhook_RestInput.receive
/model/test/intents                                POST                           evaluate_intents
/model/test/stories                                POST                           evaluate_stories
/conversations/<conversation_id>/execute           POST                           execute_action
/domain                                            GET                            get_domain
/socket.io                                         POST                           handle_request
/                                                  GET                            hello
/model                                             PUT                            load_model
/model/parse                                       POST                           parse
/conversations/<conversation_id>/predict           POST                           predict
/conversations/<conversation_id>/tracker/events    PUT                            replace_events
/conversations/<conversation_id>/story             GET                            retrieve_story
/conversations/<conversation_id>/tracker           GET                            retrieve_tracker
/webhooks/socketio                                 GET                            socketio_webhook.health
/status                                            GET                            status
/model/predict                                     POST                           tracker_predict
/model/train                                       POST                           train
/model                                             DELETE                         unload_model
/version                                           GET                            version
2019-07-12 09:16:18 INFO     root  - Starting Rasa Core server on http://localhost:5005
2019-07-12 09:16:18 INFO     root  - Enabling coroutine debugging. Loop id 140700713189400.
2019-07-12 09:16:18 DEBUG    rasa.model  - Extracted model to '/var/folders/wk/ynmgx56s43xcfzq2cc3_nmw40000gn/T/tmphsc79cp9'.
2019-07-12 09:16:18 DEBUG    rasa.model  - Extracted model to '/var/folders/wk/ynmgx56s43xcfzq2cc3_nmw40000gn/T/tmp3lzzj5hu'.
2019-07-12 09:16:18 DEBUG    pykwalify.compat  - Using yaml library: /Users/mb/.local/share/virtualenvs/rasa-lBMJeIkC/lib/python3.6/site-packages/ruamel/yaml/__init__.py
2019-07-12 09:16:20 INFO     engineio.server  - a2f80e261f624d18af25a804204d8089: Sending packet OPEN data {'sid': 'a2f80e261f624d18af25a804204d8089', 'upgrades': ['websocket'], 'pingTimeout': 60000, 'pingInterval': 25000}
2019-07-12 09:16:20 DEBUG    rasa.core.channels.socketio  - User a2f80e261f624d18af25a804204d8089 connected to socketIO endpoint.
2019-07-12 09:16:20 INFO     engineio.server  - a2f80e261f624d18af25a804204d8089: Sending packet MESSAGE data 0
2019-07-12 09:16:20 INFO     engineio.server  - a2f80e261f624d18af25a804204d8089: Received packet MESSAGE data 2["session_request",{"session_id":"96f6cff69c08401f81f457dc796240e0"}]
2019-07-12 09:16:20 INFO     socketio.server  - received event "session_request" from a2f80e261f624d18af25a804204d8089 [/]
2019-07-12 09:16:20 INFO     socketio.server  - emitting event "session_confirm" to a2f80e261f624d18af25a804204d8089 [/]
2019-07-12 09:16:20 INFO     engineio.server  - a2f80e261f624d18af25a804204d8089: Sending packet MESSAGE data 2["session_confirm","96f6cff69c08401f81f457dc796240e0"]
2019-07-12 09:16:20 DEBUG    rasa.core.channels.socketio  - User a2f80e261f624d18af25a804204d8089 connected to socketIO endpoint.
2019-07-12 09:16:20 INFO     engineio.server  - a2f80e261f624d18af25a804204d8089: Received request to upgrade to websocket
2019-07-12 09:16:20 DEBUG    websockets.protocol  - undefined - state = CONNECTING
2019-07-12 09:16:20 DEBUG    websockets.protocol  - undefined - event = connection_made(<TCPTransport closed=False reading=True 0x7ff71bd58778>)
2019-07-12 09:16:20 DEBUG    websockets.protocol  - undefined - state = OPEN
2019-07-12 09:16:20 DEBUG    websockets.protocol  - undefined < Frame(fin=True, opcode=1, data=b'2probe', rsv1=False, rsv2=False, rsv3=False)
2019-07-12 09:16:20 DEBUG    websockets.protocol  - undefined > Frame(fin=True, opcode=1, data=b'3probe', rsv1=False, rsv2=False, rsv3=False)
2019-07-12 09:16:20 DEBUG    websockets.protocol  - undefined < Frame(fin=True, opcode=1, data=b'5', rsv1=False, rsv2=False, rsv3=False)
2019-07-12 09:16:20 INFO     engineio.server  - a2f80e261f624d18af25a804204d8089: Upgrade to websocket successful
(Ella Rohm-Ensing) #6

No worries. Do you have any more info from when the user uttered actually comes in?

(Michael Bell) #7

I just copy/pasted logs. Here are a couple more user utterances…

2019-07-12 11:11:02 INFO     engineio.server  - 9cca3dc59c374a46b15c77bce70333f9: Received packet MESSAGE data 2["user_uttered",{"message":"do action","customData":{"userId":"123"},"session_id":"96f6cff69c08401f81f457dc796240e0"}]
2019-07-12 11:11:02 INFO     socketio.server  - received event "user_uttered" from 9cca3dc59c374a46b15c77bce70333f9 [/]
2019-07-12 11:11:05 DEBUG    websockets.protocol  - undefined < Frame(fin=True, opcode=1, data=b'42["user_uttered",{"message":"i am sad","customData":{"userId":"123"},"session_id":"96f6cff69c08401f81f457dc796240e0"}]', rsv1=False, rsv2=False, rsv3=False)
2019-07-12 11:11:05 INFO     engineio.server  - 9cca3dc59c374a46b15c77bce70333f9: Received packet MESSAGE data 2["user_uttered",{"message":"i am sad","customData":{"userId":"123"},"session_id":"96f6cff69c08401f81f457dc796240e0"}]
2019-07-12 11:11:05 INFO     socketio.server  - received event "user_uttered" from 9cca3dc59c374a46b15c77bce70333f9 [/]
(Michael Bell) #8

BTW, I have a custom action that is triggered on “do action” and it outputs something to the console if I am using rasa shell to interact. But using the above method, the action is not being called.

(Michael Bell) #9

BTW, does it matter what the value of rasa is in credentials.yml? I can replace that with anything and it doesn’t change the behavior.

rasa:
  url: "http://localhost:5005/api"
(Michael Bell) #10

Also, doesn’t appear to matter what I include for user_message_evt or bot_message_evt (see below). Same log messages. I also tried adding --credentials credentials.yml to command line.

socketio:
  user_message_evt: user_utttered_blah
  bot_message_evt: bot_uttered_blah
  session_persistence: true
(Michael Bell) #11

I reinstalled Rasa and it works now. :-/

(Ella Rohm-Ensing) #12

Ah I’m sorry I missed the responses to this! That’s super strange that it wasn’t working before and is working now :thinking:

I should have asked you what version you were running before, maybe when you re-installed you got an update where a bug had been fixed?

(Michael Bell) #13

1.1.4 didn’t work 1.1.6 worked

But I also monkeyed around with the 1.1.4 configuration files more whereas for the 1.1.6 version I just installed and did the minimal to enable to work with chatbot. Now I just have to figure this out:

(Ella Rohm-Ensing) #14

Ah I see, yeah it could be that something got messed up in the config files I suppose, cause I don’t think anything was actually changed in the channel between those updates.