Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Twitter DMs and Mentions do not arrive #2460

Closed
raphaelm opened this issue Jan 30, 2019 · 22 comments
Closed

Twitter DMs and Mentions do not arrive #2460

raphaelm opened this issue Jan 30, 2019 · 22 comments

Comments

@raphaelm
Copy link

Hi,

we set up Twitter integration according to the documentation ant the Channel settings do not show any errors. However, nothing arrives.

Infos:

  • Used Zammad version: 2.8.0-1548330940.ad390e9f.stretch
  • Installation method (source, package, ..): Debian package
  • Operating system: Debian stretch
  • Database + version: MariaDB

Expected behavior:

  • When someone mentions us or sends a DM, a Zammad ticket is created.

Actual behavior:

  • When someone mentions us or sends a DM, nothing happens.

Yes I'm sure this is a bug and no feature request or a general question.
Can you help us to find out what info you need for debugging?

@martini
Copy link
Collaborator

martini commented Jan 30, 2019

Hi @raphaelm Is there any hint in log/production.log (e. g. -i twitter) ?

@raphaelm
Copy link
Author

raphaelm commented Jan 30, 2019

That's the output of grep -i twitter /var/log/zammad/production.log, after removal of logging of emails we got from twitter.

I, [2019-01-30T12:43:16.877706 #5931-47137720567500]  INFO -- : Started POST "/api/v1/external_credentials/twitter/app_verify" for 2a02:…:23b0 at 2019-01-30 12:43:16 +0100
I, [2019-01-30T12:43:16.882895 #5931-47137720567500]  INFO -- :   Parameters: {"consumer_key"=>"…", "consumer_secret"=>"…", "oauth_token"=>"…", "oauth_token_secret"=>"…", "env"=>"…", "provider"=>"twitter"}
I, [2019-01-30T12:43:18.081499 #5931-47137720546680]  INFO -- : Started GET "/api/v1/channels_twitter_webhook?crc_token=…&nonce=…" for … at 2019-01-30 12:43:18 +0100
I, [2019-01-30T12:43:18.085266 #5931-47137720546680]  INFO -- : Processing by ChannelsTwitterController#webhook_verify as HTML
I, [2019-01-30T12:43:18.982109 #5931-70307650490460]  INFO -- :   Parameters: {"name"=>"twitter", "credentials"=>{"consumer_key"=>"…", "consumer_secret"=>"…", "oauth_token"=>"22133603-…", "oauth_token_secret"=>"…", "env"=>"zammad", "controller"=>"external_credentials", "action"=>"app_verify", "provider"=>"twitter", "webhook_id"=>"…"}, "id"=>"c-0"}
I, [2019-01-30T12:43:19.337857 #5931-70307339885820]  INFO -- : Started GET "/api/v1/channels_twitter?_=1548750017521" for 2a02:…:23b0 at 2019-01-30 12:43:19 +0100
I, [2019-01-30T12:43:19.344139 #5931-70307339885820]  INFO -- : Processing by ChannelsTwitterController#index as JSON
I, [2019-01-30T12:43:22.154145 #5931-47137720546680]  INFO -- : Started GET "/api/v1/external_credentials/twitter/link_account" for 2a02:…:23b0 at 2019-01-30 12:43:22 +0100
I, [2019-01-30T12:43:22.165744 #5931-47137720546680]  INFO -- :   Parameters: {"provider"=>"twitter"}
I, [2019-01-30T12:43:22.345333 #5931-47137720546680]  INFO -- : Redirected to https://api.twitter.com/oauth/authorize?oauth_token=…
I, [2019-01-30T12:43:41.122898 #5931-70307339885820]  INFO -- : Started GET "/api/v1/channels_twitter?_=1548848605494" for 2a02:…:23b0 at 2019-01-30 12:43:41 +0100
I, [2019-01-30T12:43:41.129583 #5931-70307339885820]  INFO -- : Processing by ChannelsTwitterController#index as JSON
I, [2019-01-30T12:43:42.183169 #5931-70307650490460]  INFO -- : Started GET "/api/v1/external_credentials/twitter/link_account" for 2a02:…:23b0 at 2019-01-30 12:43:42 +0100
I, [2019-01-30T12:43:42.190428 #5931-70307650490460]  INFO -- :   Parameters: {"provider"=>"twitter"}
I, [2019-01-30T12:43:42.722202 #5931-70307650490460]  INFO -- : Redirected to https://api.twitter.com/oauth/authorize?oauth_token=--…
I, [2019-01-30T12:43:45.737308 #5931-70307339871840]  INFO -- : Started GET "/api/v1/external_credentials/twitter/callback?oauth_token=--…&oauth_verifier=…" for 2a02:…:23b0 at 2019-01-30 12:43:45 +0100
I, [2019-01-30T12:43:45.744095 #5931-70307339871840]  INFO -- :   Parameters: {"oauth_token"=>"--…", "oauth_verifier"=>"…", "provider"=>"twitter"}
I, [2019-01-30T12:43:47.400984 #5931-70307339871840]  INFO -- : Redirected to https://support.rami.io/#channels/twitter/8
I, [2019-01-30T12:43:48.717842 #5931-70307339885820]  INFO -- : Started GET "/api/v1/channels_twitter?_=1548848627791" for 2a02:…:23b0 at 2019-01-30 12:43:48 +0100
I, [2019-01-30T12:43:48.723376 #5931-70307339885820]  INFO -- : Processing by ChannelsTwitterController#index as JSON
I, [2019-01-30T12:44:11.587083 #5931-70307339871840]  INFO -- : Started POST "/api/v1/channels_twitter/8" for 2a02:…:23b0 at 2019-01-30 12:44:11 +0100
I, [2019-01-30T12:44:11.597494 #5931-70307339871840]  INFO -- : Processing by ChannelsTwitterController#update as JSON
I, [2019-01-30T12:44:11.597694 #5931-70307339871840]  INFO -- :   Parameters: {"area"=>"Twitter::Account", "options"=>{"adapter"=>"twitter", "user"=>{"id"=>…, "screen_name"=>"pretixeu", "name"=>"pretix"}, "auth"=>{"external_credential_id"=>1, "oauth_token"=>"…", "oauth_token_secret"=>"…", "consumer_key"=>"…", "consumer_secret"=>"…"}, "sync"=>{"webhook_id"=>"", "track_retweets"=>false, "mentions"=>{"group_id"=>"9"}, "direct_messages"=>{"group_id"=>"9"}, "search"=>[]}}, "group_id"=>nil, "active"=>true, "id"=>"8"}
I, [2019-01-30T12:44:12.005019 #5931-47137720546680]  INFO -- : Started GET "/api/v1/channels_twitter?_=1548848627807" for 2a02:…:23b0 at 2019-01-30 12:44:12 +0100
I, [2019-01-30T12:44:12.010727 #5931-47137720546680]  INFO -- : Processing by ChannelsTwitterController#index as JSON
I, [2019-01-30T12:44:20.436356 #5931-70307374877540]  INFO -- : Started GET "/api/v1/external_credentials/twitter/link_account" for 2a02:…:23b0 at 2019-01-30 12:44:20 +0100
I, [2019-01-30T12:44:20.441759 #5931-70307374877540]  INFO -- :   Parameters: {"provider"=>"twitter"}
I, [2019-01-30T12:44:20.776232 #5931-70307374877540]  INFO -- : Redirected to https://api.twitter.com/oauth/authorize?oauth_token=…
I, [2019-01-30T12:44:23.329907 #5931-70307339885820]  INFO -- : Started GET "/api/v1/external_credentials/twitter/callback?oauth_token=…&oauth_verifier=…" for 2a02:…:23b0 at 2019-01-30 12:44:23 +0100
I, [2019-01-30T12:44:23.335028 #5931-70307339885820]  INFO -- :   Parameters: {"oauth_token"=>"…", "oauth_verifier"=>"…", "provider"=>"twitter"}
I, [2019-01-30T12:44:24.963013 #5931-70307339885820]  INFO -- : Redirected to https://support.rami.io/#channels/twitter/8
I, [2019-01-30T12:44:26.218570 #5931-47137720546680]  INFO -- : Started GET "/api/v1/channels_twitter?_=1548848665152" for 2a02:…:23b0 at 2019-01-30 12:44:26 +0100
I, [2019-01-30T12:44:26.226071 #5931-47137720546680]  INFO -- : Processing by ChannelsTwitterController#index as JSON
I, [2019-01-30T12:44:28.066560 #5931-47137720546680]  INFO -- : Started POST "/api/v1/channels_twitter/8" for 2a02:…:23b0 at 2019-01-30 12:44:28 +0100
I, [2019-01-30T12:44:28.076235 #5931-47137720546680]  INFO -- : Processing by ChannelsTwitterController#update as JSON
I, [2019-01-30T12:44:28.076351 #5931-47137720546680]  INFO -- :   Parameters: {"area"=>"Twitter::Account", "options"=>{"adapter"=>"twitter", "user"=>{"id"=>4362252801, "screen_name"=>"pretixeu", "name"=>"pretix"}, "auth"=>{"external_credential_id"=>1, "oauth_token"=>"…", "oauth_token_secret"=>"…", "consumer_key"=>"…", "consumer_secret"=>"…"}, "sync"=>{"webhook_id"=>"", "track_retweets"=>false, "mentions"=>{"group_id"=>"9"}, "direct_messages"=>{"group_id"=>"9"}, "search"=>[]}, "subscribed_to_webhook_id"=>"…"}, "group_id"=>nil, "active"=>true, "id"=>"8"}
I, [2019-01-30T12:44:28.742588 #5931-70307339885820]  INFO -- : Started GET "/api/v1/channels_twitter?_=1548848665162" for 2a02:…:23b0 at 2019-01-30 12:44:28 +0100
I, [2019-01-30T12:44:28.752236 #5931-70307339885820]  INFO -- : Processing by ChannelsTwitterController#index as JSON
I, [2019-01-30T12:48:46.835649 #5931-70307339885820]  INFO -- : Started GET "/api/v1/channels_twitter?_=1548848665187" for 2a02:…:23b0 at 2019-01-30 12:48:46 +0100
I, [2019-01-30T12:48:46.843058 #5931-70307339885820]  INFO -- : Processing by ChannelsTwitterController#index as JSON

@martini
Copy link
Collaborator

martini commented Jan 30, 2019

I, [2019-01-30T12:43:18.081499 #5931-47137720546680]  INFO -- : Started GET "/api/v1/channels_twitter_webhook?crc_token=…&nonce=…" for … at 2019-01-30 12:43:18 +0100
I, [2019-01-30T12:43:18.085266 #5931-47137720546680]  INFO -- : Processing by ChannelsTwitterController#webhook_verify as HTML
I, [2019-01-30T12:43:18.982109 #5931-70307650490460]  INFO -- :   Parameters: {"name"=>"twitter", "credentials"=>{"consumer_key"=>"…", "consumer_secret"=>"…", "oauth_token"=>"22133603-…", "oauth_token_secret"=>"…", "env"=>"zammad", "controller"=>"external_credentials", "action"=>"app_verify", "provider"=>"twitter", "webhook_id"=>"…"}, "id"=>"c-0"}

I see a verify call from twitter to verify your web hook. But I see no http calls from twitter to your webhook.

-=> It seems twitter is not sending messages to your webhook. You have a https host, right? Maybe something wrong which your ssl cert? Any other errors in log/production.log which is related to twitter?

@rixx
Copy link

rixx commented Jan 31, 2019

We run into the same problem on our instance, running the current release.

@nicolaswurtz
Copy link

nicolaswurtz commented Jan 31, 2019

Same here, I've found something that could help ?
No such channel for user id '1090618064528424961'! (Exceptions::UnprocessableEntity)

I, [2019-01-31T12:53:22.891153 #1-70353379302120]  INFO -- : Started POST "/api/v1/channels_twitter_webhook" for ::ffff:172.21.0.10 at 2019-01-31 12:53:22 +0000
I, [2019-01-31T12:53:22.896366 #1-70353379302120]  INFO -- : Processing by ChannelsTwitterController#webhook_incoming as HTML
I, [2019-01-31T12:53:22.896571 #1-70353379302120]  INFO -- :   Parameters: {" some data removed "}
E, [2019-01-31T12:53:22.960167 #1-70353379302120] ERROR -- : No such channel for user id '1090618064528424961'! (Exceptions::UnprocessableEntity)
/opt/zammad/app/controllers/channels_twitter_controller.rb:32:in 'validate_webhook_signature!'

@nicolaswurtz
Copy link

nicolaswurtz commented Jan 31, 2019

@MrGeneration
Copy link
Member

@nicolaswurtz This is related to the community issue, we still haven't found the cause yet, it would be great if we could keep the discussion regarding this off this tracker. :-)

@raphaelm Please give Feedback to Martin, especially about the SSL question.

@rixx Exact same problem as @raphaelm ? Please provide logfiles.

@raphaelm
Copy link
Author

raphaelm commented Feb 1, 2019

@martini

-=> It seems twitter is not sending messages to your webhook. You have a https host, right?

Yes.

Maybe something wrong which your ssl cert?

Not that I can think of: https://www.ssllabs.com/ssltest/analyze.html?d=support.rami.io&latest

Any other errors in log/production.log which is related to twitter?

I can't find any.

Does Twitter provide any tool to debug webhooks? I couldn't find anything.

@nicolaswurtz
Copy link

I think this is really the same issue — @raphaelm could you add -A 1 to your grep command to see one line after ? The error doesn't contain "twitter" word, I guess we'll see the same line I have.

E, [2019-01-31T12:53:22.960167 #1-70353379302120] ERROR -- : No such channel for user [...]

@raphaelm
Copy link
Author

raphaelm commented Feb 5, 2019

Nope, not the same issue. "No such channel for user" doesn't appear in the log and I already checked that the user IDs match

@MrGeneration
Copy link
Member

Okay, so we might have two different issues here @martini

@MrGeneration
Copy link
Member

Small update on the issue.
We learned that this only takes place if the user id is too long.
This was found by a community user "abelxluck".

The post can be found here: https://community.zammad.org/t/dont-receive-twitter-dms-railsserver-error/1799/34

@schiederme
Copy link

Any updates or fixes in the meantime?

@thorsteneckel
Copy link
Contributor

Hey @schiederme - unfortunately no updates yet. As @MrGeneration described earlier there has been some research in the community indicating that the stored ID might be wrong. I wrote a little script to compare the stored ID with the ID we receive from the Twitter API for each Twitter channel. It will also print out the ID so you can/should verify that this is the actual ID of your account. Feedback welcome!

    Channel.where(area: 'Twitter::Account').each do |channel|
      client = Twitter::REST::Client.new do |config|
        config.consumer_key        = channel.options['auth']['consumer_key']
        config.consumer_secret     = channel.options['auth']['consumer_secret']
        config.access_token        = channel.options['auth']['oauth_token']
        config.access_token_secret = channel.options['auth']['oauth_token_secret']
      end

      if channel.options['user']['id'] != client.user.id
        puts "ATTENTION: Found ID mismatch. Local ID '#{channel.options['user']['id']}' doesn't match with received remote ID '#{client.user.id}'."
      else
        puts "Local ID '#{channel.options['user']['id']}' matches with received remote ID. Please double check if this is the ID of your twitter account (via e.g. https://tweeterid.com)."
      end
    end

Output looks like this:
Local ID '785412523193425920' matches with received remote ID. Please double check if this is the ID of your twitter account (via e.g. https://tweeterid.com).

You can execute it by creating a file called debug_issue.rb in your Zammad directory (usually /opt/zammad). Then run the file from your Zammad directory via zammad run rails r debug_issue.rb or rails r debug_issue.rb as zammad user, depending on your installation source (package/source). After you're done you can/should delete the debug_issue.rb file.

@MrXermon
Copy link

MrXermon commented Nov 4, 2019

I tried the script with my account (@level66network at Twitter) and my Zammad installation, too, and it looks like the IDs do actually mismatch in the installation.

ATTENTION: Found ID mismatch. Local ID '1170020461641642000' doesn't match with received remote ID '1170020461641641990'.

In my logs i also find the following issue triggered by the webhook.

No such channel for user id '1170020461641641990'! (Exceptions::UnprocessableEntity)

@thorsteneckel
Copy link
Contributor

Wow! This is really it! We found out that the ID is properly send from the backend (Ruby) to the frontend (JavaScript) which then breaks the number because it can't handle this large integers properly, as "abelxluck" found out here.

So the error occurs once you open a Twitter channel to edit it and save your changes afterwards. After this point you won't be able to receive Twitter direct messages.

You can fix your broken channels by running the command:

Channel.where(area: 'Twitter::Account').each do |channel|

  client = Twitter::REST::Client.new do |config|
    config.consumer_key        = channel.options['auth']['consumer_key']
    config.consumer_secret     = channel.options['auth']['consumer_secret']
    config.access_token        = channel.options['auth']['oauth_token']
    config.access_token_secret = channel.options['auth']['oauth_token_secret']
  end

  channel.options['user']['id'] = client.user.id

  channel.save!
end

Via the Zammad rails console.

However, this will only work until you go and save/edit your Twitter channel via the admin interface again. We're working on a sustainable solution for this.

@rlue - can you please take over from here? We need to convert the ID to a string and store it that way. My hot fix script could be the starting point for the required migration. Besides from that we need to change the code that initially fetches and stores the ID as an integer. Additionally we need to find the other places that use the ID and make sure they handle the string version properly.

@thorsteneckel
Copy link
Contributor

I forgot to mention: Thanks a ton @MrXermon for jumping in that fast! Your input and the one of abelxluck helped me to find the root cause in the Zammad context. Fix is on the way 🚂

@schiederme
Copy link

Thank you @thorsteneckel, the work around works!

@MrXermon
Copy link

MrXermon commented Nov 4, 2019

Thank you @thorsteneckel for creating the workaround! It works with my system, too! <3

@rlue rlue added this to In progress in OLD Workflow Nov 6, 2019
@rlue
Copy link
Contributor

rlue commented Nov 6, 2019

Additionally we need to find the other places that use the ID and make sure they handle the string version properly.

@thorsteneckel, is it safe to assume that

$ grep "\['user'\]\['id'\]"

should find all the instances we're looking for?

@thorsteneckel
Copy link
Contributor

thorsteneckel commented Nov 6, 2019

I'd suggest to dig for 'Twitter::Account'. That is the identifier for all Twitter-Channels, that have the id stored in the options attribute.

@rlue rlue moved this from In progress to QA in OLD Workflow Nov 7, 2019
zammad-sync pushed a commit that referenced this issue Nov 12, 2019
…age functionality

In some cases, editing a Twitter account via the admin panel
would cause new DMs to stop coming in. Why?

All Twitter usernames correspond to a numeric user ID
(see https://tweeterid.com/).
Zammad stores this ID on Twitter channels
(under `channel.options['user']['id']`)
and uses it to monitor incoming DMs.

Zammad was storing these user IDs to the DB as integers,
then passing those values to the frontend (JS) for account editing.
Some user IDs are longer than JavaScript's `Number.MAX_SAFE_INTEGER`,
and so got truncated on their way back to the update endpoint
(e.g., 984608854112718800 instead of 984608854112718848).

This commit enforces string storage of Twitter user IDs on new channels,
and includes a migration to verify and stringify IDs on existing ones.

Zammad Community: https://community.zammad.org/t/1799/34
GitHub: #2460
@thorsteneckel thorsteneckel moved this from QA to Done in OLD Workflow Nov 12, 2019
@thorsteneckel thorsteneckel added this to the 3.2.0 milestone Nov 12, 2019
@thorsteneckel
Copy link
Contributor

Fixed with the commit above. Will be released with Zammad 3.2 which will arrive soon (1-2 weeks).

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
No open projects
OLD Workflow
  
Done
Development

No branches or pull requests

9 participants