skoczen / will

Will is a simple, beautiful-to-code bot for slack, hipchat, and a whole lot more.
https://heywill.io
MIT License
406 stars 171 forks source link

Error reading from XML stream. #246

Closed ferodia closed 7 years ago

ferodia commented 7 years ago

Hello, I am not able to get will running. I get the follwoing error: Starting core processes: ✓ Web server started. ✓ Scheduler started. ERROR "Bot room" is not an available room, ask "@WillBOTSEG what are the rooms?" for the full list. ✓ Chat client started. ✓ Will is running. ERROR Error reading from XML stream. ERROR Error processing event handler: <bound method WillBot.session_start of <will.main.WillBot object at 0x7f74a7d72b50>> Traceback (most recent call last): File "/home/Envs/my-will/local/lib/python2.7/site-packages/sleekxmpp/xmlstream/xmlstream.py", line 1699, in _event_runner func(*args) File "/home/Envs/my-will/local/lib/python2.7/site-packages/will/listener.py", line 64, in session_start self.get_roster() File "/home/Envs/my-will/local/lib/python2.7/site-packages/sleekxmpp/clientxmpp.py", line 258, in get_roster response = iq.send(block, timeout, callback) File "/home/Envs/my-will/local/lib/python2.7/site-packages/sleekxmpp/stanza/iq.py", line 233, in send raise IqTimeout(self) IqTimeout ERROR Request timed out: ERROR CERT: Invalid certificate trust chain. ERROR Error reading from XML stream.

Could you please help ? thanks

brandonsturgeon commented 7 years ago

Hi there

Do you know if this is a self hosted version of Hipchat?

It looks like the error has to do with authentication or certificates based on ERROR CERT: Invalid certificate trust chain.

Also, this error appears at the top of the log: ERROR "Bot room" is not an available room, ask "@WillBOTSEG what are the rooms?" for the full list.

Does the room "Bot room" exist in your hipchat? If so, that could help us identify the problem.

ferodia commented 7 years ago

Hi, Thanks for your reply. Yes, it is an internal server. For your second point, actually it was a newly created room, the error disappears if I use a room id created a while ago.

brandonsturgeon commented 7 years ago

I don't think the XML error is relevant. I'm sure that's just a connection terminating because of another error.

I'd urge you to take a look through your will config and be 100% sure you have all of the authentication settings and URLs properly set.

If you're able to share it, I'd also be glad to help you do that, but I understand that it can (and often does) contain confidential information.

ferodia commented 7 years ago

Hello, Thank you for your reply, after some investigation, it seems to be an issue with the certificate, therefore my questions is : is there a way to bypass the ssl certificate validation like it's possible for http protocol?

brandonsturgeon commented 7 years ago

I'm not very good with networking, so this is a bit out of my ability to help. I've dug through SleekXMPP's codebase for a bit and I've only created more questions than answers. It seems like it shouldn't even be checking for certificates unless it's explicitly told to..

However, I will say that it seems like your network requires a special certificate. Perhaps you could make sure that the required certificate is installed on the machine you're running Will from?

ferodia commented 7 years ago

I finally managed to make it work. Basically I disabled the certificate check with the parameter in config file + I added this magic line of code to the file listener.py line 54 self.add_event_handler('ssl_expired_cert', lambda cert: True) I admit it is not safe, but it is good enough to unblock me for the moment :) Thanks a lot for your support!

brandonsturgeon commented 7 years ago

That's great to hear! Nice going.

What was the parameter in the config file that you added?

ferodia commented 7 years ago

I just uncommented this: ALLOW_INSECURE_HIPCHAT_SERVER = True I am closing this issue.

brandonsturgeon commented 7 years ago

D'oh! I've even used that config before to solve a similar issue.

Glad you were able to figure it out!

galbacarys commented 7 years ago

I tried the above steps, and none of them worked for me. Do you guys have any other suggestions?

Thanks!

misterf13 commented 7 years ago

Same here, still not working. I am using a personal hipchat server for testing so I could be messing up elsewhere.

I wonder if the namespaces are right.

Fri, 30 Jun 2017 06:55:30 [DEBUG] SEND (IMMED): <stream:stream to='localhipchatserver.com' xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:client' xml:lang='en' version='1.0'>

skoczen commented 7 years ago

@fgarcia13 can you provide more details on your setup?

misterf13 commented 7 years ago

@skoczen For Will I am using the following modules. APScheduler-2.1.2-0.x86 args-0.1.0-0.x86 CherryPy-3.6.0-0.x86 clint-0.3.7-0.x86 dill-0.2.1-0.x86 hiredis-0.2.0-0.x86 Markdown-2.3.1-0.x86 natural-0.1.5-0.x86 parsedatetime-1.1.2-0.x86 pyasn1-0.0.5-0.x86 pyasn1-0.1.7-0.x86 pyasn1-modules-2.0 pygerduty-0.28-0.x86 pygerduty-0.35.2-0.x86 pygit2-0.0.1-0.x86 PyYAML-3.10-0.x86 requests-2.4.1-0.x86 sleekxmpp-1.3.1-0.x86 will-0.9.5-0.x86

Here is some debug output.


$ ./run_will.py 

      ___/-\___
  ___|_________|___
     |         |
     |--O---O--|
     |         |
     |         |
     |  \___/  |
     |_________|

      Will: Hi!

Verifying environment...
  ✓ WILL_USERNAME
  ✓ WILL_PASSWORD
  ✓ WILL_V2_TOKEN

Verifying credentials...
Fri, 30 Jun 2017 06:54:42 [INFO] Starting new HTTPS connection (1): hipchat.local
Fri, 30 Jun 2017 06:54:42 [DEBUG] "GET /v2/user/1171?auth_token=18ksjdf0gl3lWGLbcW8HWYgtqMtoww9icruVTLxu HTTP/1.1" 200 None
  ✓ svc_will authenticated
  ✓ @will verified as handle

Loading configuration...
  Importing config.py... 
    ✓ Valid.
  Verifying settings... 
    ! Warning: no V1_TOKEN found in the environment or config.This is generally ok, but if you have more than 30 rooms, you may recieve rate-limit errors without one.
    ✓ ALLOW_INSECURE_HIPCHAT_SERVER
    ✓ ADMINS
    ✓ DEFAULT_ROOM
    ✓ FILE_DIR
    ✓ HANDLE
    ✓ HTTPSERVER_PORT
    ✓ HIPCHAT_SERVER
    ✓ LOGLEVEL
    ✓ NAME
    ✓ PASSWORD
    ✓ PLUGIN_BLACKLIST
    ✓ PUBLIC_URL
    ✓ PLUGINS
    ✓ ROOMS
    ✓ REQUESTS_OPTIONS
    ✓ STORAGE_BACKEND
    ✓ TEMPLATE_DIRS_PICKLED
    ✓ USERNAME
    ✓ USE_PROXY
    ✓ V2_TOKEN

Verifying rooms...
  ✓ Joining the 1 room specified.

Bootstrapping storage...
Fri, 30 Jun 2017 06:54:42 [DEBUG] Using /home/fgarcia13/svc_will/settings for local setting storage
  ✓ Bootstrapped!

Bootstrapping plugins...

  Administrative actions ------------------------------------------------ will.plugins.admin
    ✓ KeepAlive
    ✓ Say
    ✓ Storage
    ✓ Ping
    ✓ Version

  Hipchat actions --------------------------------------------------- will.plugins.chat_room
    ✓ NewTopic
    ✓ Rooms
    ✓ Roster

  Help ------------------------------------------------------------------- will.plugins.help
    ✓ Help
    ✓ ProgrammerHelp

  Plugins -------------------------------------------------------------------------- plugins
    ✓ Morning

  Web pages --------------------------------------------------------------- will.plugins.web
    ✓ HomePage

Verifying settings requested by plugins...
  ✓ PUBLIC_URL

Bootstrapping complete.

Starting core processes:
  ✓ Web server started.
Fri, 30 Jun 2017 06:54:43 [DEBUG] Loaded Plugin: RFC 6120: Stream Feature: STARTTLS
Fri, 30 Jun 2017 06:54:43 [DEBUG] Loaded Plugin: RFC 6120: Stream Feature: Resource Binding
Fri, 30 Jun 2017 06:54:43 [DEBUG] Loaded Plugin: RFC 3920: Stream Feature: Start Session
Fri, 30 Jun 2017 06:54:43 [DEBUG] Loaded Plugin: RFC 6121: Stream Feature: Roster Versioning
Fri, 30 Jun 2017 06:54:43 [DEBUG] Loaded Plugin: RFC 6121: Stream Feature: Subscription Pre-Approval
  ✓ Scheduler started.
Fri, 30 Jun 2017 06:54:43 [DEBUG] Loaded Plugin: RFC 6120: Stream Feature: SASL
Fri, 30 Jun 2017 06:54:43 [DEBUG] Loaded Plugin: XEP-0030: Service Discovery
Fri, 30 Jun 2017 06:54:43 [DEBUG] Loaded Plugin: XEP-0004: Data Forms
Fri, 30 Jun 2017 06:54:43 [DEBUG] Loaded Plugin: XEP-0045: Multi-User Chat
Fri, 30 Jun 2017 06:54:43 [DEBUG] DNS: Querying SRV records for hipchat.local
Fri, 30 Jun 2017 06:54:43 [DEBUG] DNS: No SRV records for hipchat.local.
Fri, 30 Jun 2017 06:54:43 [DEBUG] DNS: Querying hipchat.local for AAAA records.
Fri, 30 Jun 2017 06:54:43 [DEBUG] DNS: No AAAA records for hipchat.local
Fri, 30 Jun 2017 06:54:43 [DEBUG] DNS: Querying hipchat.local for A records.
Fri, 30 Jun 2017 06:54:43 [DEBUG] Connecting to 10.10.10.10:5222
Fri, 30 Jun 2017 06:54:43 [DEBUG] Event triggered: connected
Fri, 30 Jun 2017 06:54:43 [DEBUG]  ==== TRANSITION disconnected -> connected
  ✓ Chat client started.
  ✓ Will is running.
Fri, 30 Jun 2017 06:54:43 [DEBUG] Starting HANDLER THREAD
Fri, 30 Jun 2017 06:54:43 [DEBUG] Loading event runner
Fri, 30 Jun 2017 06:54:43 [DEBUG] SEND (IMMED): <stream:stream to='hipchat.local' xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:client' xml:lang='en' version='1.0'>
Fri, 30 Jun 2017 06:55:00 [INFO] Starting new HTTP connection (1): localhost
Fri, 30 Jun 2017 06:55:00 [DEBUG] "GET /keep-alive HTTP/1.1" 404 208
Fri, 30 Jun 2017 06:55:28 [DEBUG] Scheduled event: Session timeout check: ()
Fri, 30 Jun 2017 06:55:28 [DEBUG] Session start has taken more than 45 seconds
Fri, 30 Jun 2017 06:55:28 [DEBUG] Event triggered: session_end
Fri, 30 Jun 2017 06:55:28 [DEBUG] SEND (IMMED): </stream:stream>
Fri, 30 Jun 2017 06:55:28 [INFO] Waiting for </stream:stream> from server
Fri, 30 Jun 2017 06:55:28 [DEBUG] Event triggered: disconnected
Fri, 30 Jun 2017 06:55:28 [ERROR] Error reading from XML stream.

I'll have to find out a bit more about the local hipchat server setup. Thank you.

woohgit commented 7 years ago

What is sure that the IqTimeout should be handled like this:

    # Most get_*/set_* methods from plugins use Iq stanzas, which
    # can generate IqError and IqTimeout exceptions
    #
    # try:
    #     self.get_roster()
    # except IqError as err:
    #     logging.error('There was an error getting the roster')
    #     logging.error(err.iq['error']['condition'])
    #     self.disconnect()
    # except IqTimeout:
    #     logging.error('Server is taking too long to respond')
    #     self.disconnect()

Maybe killing will itself is the best when this happens, since this could happen ( and happened to me ) with non private hipchat server too. Maybe a network glitch or they've upgraded/updated the ssl certs. Who knows.