googleworkspace / hubot-google-hangouts-chat

Hubot adapter for Google Chat.
Apache License 2.0
24 stars 17 forks source link

Problem troubleshooting non responsiveness of hubot chatbot #3

Open a4sh3u opened 5 years ago

a4sh3u commented 5 years ago

Hi, I'm trying to run hubot locally and configured it using gcp pub/sub adapter. I published my bot on hangout chat as well following this guide https://developers.google.com/hangouts/chat/how-tos/integrate-hubot

It shows up as green in chat (so I think it is connecting with my app), but I don't get any response back from the bot. So, I tried getting logs from my docker container, where I'm running it. But, it doesn't contain any relevant information. This blocks me to do anything further. Any help is appreciated.

Here is my Dockerfile

FROM node:latest

ENV DEBIAN_FRONTEND=noninteractive \
    HUBOT_NAME=myhubot \
    HUBOT_OWNER=none \
    HUBOT_DESCRIPTION=Hubot \
    EXTERNAL_SCRIPTS="hubot-help,hubot-pugme" \
    PORT=8080 \
    EXPRESS_PORT=8081 \
    IS_PUBSUB=true \
    PUBSUB_PROJECT_ID='hubot-hangout-project' \
    PUBSUB_SUBSCRIPTION_ID='testsub' \
    GOOGLE_APPLICATION_CREDENTIALS='/home/hubot/cred/hubot-hangout-project-07a6200156ce.json'

RUN useradd hubot -m && \
    npm install -g hubot coffeescript yo generator-hubot && \
    npm install hubot-google-hangouts-chat

USER hubot

WORKDIR /home/hubot

RUN yo hubot --owner="${HUBOT_OWNER}" --name="${HUBOT_NAME}" --description="${HUBOT_DESCRIPTION}" --defaults && \
    sed -i /heroku/d ./external-scripts.json && \
    sed -i /redis-brain/d ./external-scripts.json && \
    npm install hubot-scripts --save && \
    node -e "console.log(JSON.stringify('$EXTERNAL_SCRIPTS'.split(',')))" > external-scripts.json && \
    npm install $(node -e "console.log('$EXTERNAL_SCRIPTS'.split(',').join(' '))")

EXPOSE 8080 8081

VOLUME ["/home/hubot/scripts"]

CMD bin/hubot -n $HUBOT_NAME --adapter google-hangouts-chat

And here are my logs

audited 178 packages in 1.296s found 0 vulnerabilities

body-parser deprecated undefined extended: provide extended option node_modules/hubot/src/robot.js:445:21 [Fri Dec 07 2018 15:31:43 GMT+0000 (Coordinated Universal Time)] INFO Connecting to Pub/Sub subscription - projects/hubot-hangout-project/subscriptions/testsub [Fri Dec 07 2018 15:31:43 GMT+0000 (Coordinated Universal Time)] INFO Hangouts Chat adapter initialized successfully [Fri Dec 07 2018 15:31:43 GMT+0000 (Coordinated Universal Time)] WARNING Loading scripts from hubot-scripts.json is deprecated and will be removed in 3.0 (https://github.com/github/hubot-scripts/issues/1113) in favor of packages for each script.

Your hubot-scripts.json is empty, so you just need to remove it. (node:8) DeprecationWarning: grpc.load: Use the @grpc/proto-loader module with grpc.loadPackageDefinition instead

kumarse commented 5 years ago

Can you try exporting HUBOT_LOG_LEVEL="debug" environment variable and then retrieve logs. It should give you more detailed logs

In cloud pub/sub mode, we print the received message. Please check if you see them.

a4sh3u commented 5 years ago

@kumarse Thanks. Now, I'm getting some output from my container, but I'm not sure what it is though.It would be really helpful if you could take some time to explain it. Thanks

audited 178 packages in 1.467s found 0 vulnerabilities

body-parser deprecated undefined extended: provide extended option node_modules/hubot/src/robot.js:445:21 [Thu Dec 13 2018 12:58:52 GMT+0000 (Coordinated Universal Time)] DEBUG Loading adapter google-hangouts-chat [Thu Dec 13 2018 12:58:52 GMT+0000 (Coordinated Universal Time)] INFO Connecting to Pub/Sub subscription - projects/hubot-hangout-project/subscriptions/myhubotsubscription [Thu Dec 13 2018 12:58:52 GMT+0000 (Coordinated Universal Time)] INFO Hangouts Chat adapter initialized successfully [Thu Dec 13 2018 12:58:52 GMT+0000 (Coordinated Universal Time)] DEBUG Loading scripts from /home/hubot/scripts [Thu Dec 13 2018 12:58:52 GMT+0000 (Coordinated Universal Time)] DEBUG Parsing help for /home/hubot/scripts/example.coffee [Thu Dec 13 2018 12:58:52 GMT+0000 (Coordinated Universal Time)] DEBUG Loading scripts from /home/hubot/src/scripts [Thu Dec 13 2018 12:58:52 GMT+0000 (Coordinated Universal Time)] DEBUG Loading hubot-scripts from /home/hubot/node_modules/hubot-scripts/src/scripts [Thu Dec 13 2018 12:58:52 GMT+0000 (Coordinated Universal Time)] WARNING Loading scripts from hubot-scripts.json is deprecated and will be removed in 3.0 (https://github.com/github/hubot-scripts/issues/1113) in favor of packages for each script.

Your hubot-scripts.json is empty, so you just need to remove it. (node:8) DeprecationWarning: grpc.load: Use the @grpc/proto-loader module with grpc.loadPackageDefinition instead [Thu Dec 13 2018 12:58:52 GMT+0000 (Coordinated Universal Time)] DEBUG Loading external-scripts from npm packages [Thu Dec 13 2018 12:58:52 GMT+0000 (Coordinated Universal Time)] DEBUG Parsing help for /home/hubot/node_modules/hubot-help/src/help.js [Thu Dec 13 2018 12:58:52 GMT+0000 (Coordinated Universal Time)] DEBUG Parsing help for /home/hubot/node_modules/hubot-pugme/src/pugme.coffee [Thu Dec 13 2018 13:04:52 GMT+0000 (Coordinated Universal Time)] DEBUG Received message 288181954326697: [Thu Dec 13 2018 13:04:52 GMT+0000 (Coordinated Universal Time)] DEBUG Data: {"type":"MESSAGE","eventTime":"2018-12-13T13:04:51.066799Z","token":"*****","message":{"name":"spaces/3JbDbAAAAAE/messages/S3wSQWExhI4.S3wSQWExhI4","sender":{"name":"users/*","displayName":"Ashutosh Singh","avatarUrl":"https://lh6.googleusercontent.com/-6GR-V1eEnS8/AAAAAAAAAAI/AAAAAAAAAAA/AGDgw-i5r1NDT2HFKNikBWVEGN5NmqguYw/mo/photo.jpg","email":"dummyemail@etc.com","type":"HUMAN"},"createTime":"2018-12-13T13:04:51.066799Z","text":"help","thread":{"name":"spaces/3JbDbAAAAAE/threads/S3wSQWExhI4","retentionSettings":{"state":"PERMANENT"}},"space":{"name":"spaces/3JbDbAAAAAE","type":"DM"},"argumentText":"help"},"user":{"name":"users/*********************","displayName":"Ashutosh Singh","avatarUrl":"https://lh6.googleusercontent.com/-6GR-V1eEnS8/AAAAAAAAAAI/AAAAAAAAAAA/AGDgw-i5r1NDT2HFKNikBWVEGN5NmqguYw/mo/photo.jpg","email":"dummyemail@etc.com","type":"HUMAN"},"space":{"name":"spaces/3JbDbAAAAAE","type":"DM"},"configCompleteRedirectUrl":"https://chat.google.com/api/bot_config_complete?token*"} [Thu Dec 13 2018 13:04:52 GMT+0000 (Coordinated Universal Time)] DEBUG No listeners executed; falling back to catch-all [Thu Dec 13 2018 13:06:04 GMT+0000 (Coordinated Universal Time)] DEBUG Received message 327070168068321: [Thu Dec 13 2018 13:06:04 GMT+0000 (Coordinated Universal Time)] DEBUG Data: {"type":"MESSAGE","eventTime":"2018-12-13T13:06:02.342175Z","token":"","message":{"name":"spaces/AAAA5ByGSsI/messages/XRt8HR_VbD8.XRt8HR_VbD8","sender":{"name":"users/","displayName":"Ashutosh Singh","avatarUrl":"https://lh6.googleusercontent.com/-6GR-V1eEnS8/AAAAAAAAAAI/AAAAAAAAAAA/AGDgw-i5r1NDT2HFKNikBWVEGN5NmqguYw/mo/photo.jpg","email":"dummyemail@etc.com","type":"HUMAN"},"createTime":"2018-12-13T13:06:02.342175Z","text":"@myhubot help","annotations":[{"type":"USER_MENTION","startIndex":0,"length":8,"userMention":{"user":{"name":"users/","displayName":"myhubot","avatarUrl":"https://lh4.googleusercontent.com/proxy/t56h-DMnCanP1mTqDJrc4ZQdy_hIlaEU4veE4Y-lWl3haEWDknfiwSV1Kt-RKwj8Ju5JOwlp93_xTSyUZh-M-XDc6ON4No06SrlLXD7h1d36HxBpam2frLMj2zR40Vp-bI7S5xo","type":"BOT"},"type":"MENTION"}}],"thread":{"name":"spaces/AAAA5ByGSsI/threads/XRt8HR_VbD8","retentionSettings":{"state":"PERMANENT"}},"space":{"name":"spaces/AAAA5ByGSsI","type":"ROOM","displayName":"testhubot"},"argumentText":" help"},"user":{"name":"users/*","displayName":"Ashutosh Singh","avatarUrl":"https://lh6.googleusercontent.com/-6GR-V1eEnS8/AAAAAAAAAAI/AAAAAAAAAAA/AGDgw-i5r1NDT2HFKNikBWVEGN5NmqguYw/mo/photo.jpg","email":"dummyemail@etc.com","type":"HUMAN"},"space":{"name":"spaces/AAAA5ByGSsI","type":"ROOM","displayName":"testhubot"},"configCompleteRedirectUrl":"https://chat.google.com/api/bot_config_complete?token***"} [Thu Dec 13 2018 13:06:04 GMT+0000 (Coordinated Universal Time)] DEBUG No listeners executed; falling back to catch-all [Thu Dec 13 2018 13:06:11 GMT+0000 (Coordinated Universal Time)] DEBUG Received message 327069832882743: