Sentry ignoring requests from certain servers

326 views
Skip to first unread message

seraph...@gmail.com

unread,
Jun 19, 2013, 4:18:33 AM6/19/13
to gets...@googlegroups.com
Hi Guys,

I have Sentry working in our dev environment (Open Source edition).  But when I roll our implementation of RavenJava out to our staging environment it does not work.  The only difference I can see (aside from the IP address range) is that the Staging environment accesses sentry via a firewall which is port forwarding port 9000 to the sentry server.  The firewall is logging that the packet is accepted and forwarded to the sentry server, but sentry seems to be ignoring the request.  I am not asking for firewall help, but I am asking how to put sentry into some kind of debug mode so that I can see if the request is coming in to sentry.  I know it is getting to the sentry server because a netstat confirms the packets coming in.  I have also connected to port 9000 through the firewall and sentry accepts the connection (see below).  It is extremely difficult to search for "enable logging on sentry" since sentry's function is to log errors.

I have tracked/traced the packets to the sentry server and now I basically just need help debugging sentry, as I need to find out what is sentry doing to the request and why is it ignoring it.  Perhaps the HTTP request is being changed by the firewall, but I cannot check that without seeing what sentry is doing with the request.  Please help!

Test Via Firewall

root@host:~$ telnet 172.16.3.6 9000
Trying 172.16.3.6...
Connected to 172.16.3.6.
Escape character is '^]'.
GET / HTTP/1.1
Host: 172.16.3.6:9000
Accept: text/plain

HTTP/1.1 302 FOUND
Server: gunicorn/0.17.4
Date: Wed, 19 Jun 2013 08:14:27 GMT
Connection: close
Transfer-Encoding: chunked
Vary: Accept-Language, Cookie
Content-Type: text/html; charset=utf-8
Location: http://172.16.3.6:9000/login/
Content-Language: en-us
Set-Cookie: sessionid=7bdde47cb3e60f6c1fee2454162ad4f4; expires=Wed, 03-Jul-2013 08:14:27 GMT; httponly; Max-Age=1209600; Path=/

0

Connection closed by foreign host.

Regards,
Seraph

David Cramer

unread,
Jun 19, 2013, 4:31:30 AM6/19/13
to gets...@googlegroups.com
Hey Seraph 

A few things:

- Sentry might be throwing an internal error. Run 'sentry repair --owner=yourusername' and check the internal project
- it could be an issue with host forwarding
- you might need to set SENTRY_URL_PREFIX

--
You received this message because you are subscribed to the Google Groups "sentry" group.
To unsubscribe from this group and stop receiving emails from it, send an email to getsentry+...@googlegroups.com.
For more options, visit https://groups.google.com/groups/opt_out.
 
 


--
--
David Cramer
http://disqus.com/zeeg
http://twitter.com/zeeg

seraph...@gmail.com

unread,
Jun 19, 2013, 5:36:11 AM6/19/13
to gets...@googlegroups.com
Thanks David,  Here is my feedback to what you suggested:


On Wednesday, June 19, 2013 10:31:30 AM UTC+2, David Cramer wrote:
Hey Seraph 

A few things:

- Sentry might be throwing an internal error. Run 'sentry repair --owner=yourusername' and check the internal project

(sentry)admin2@Dynobuntu16:~$ sentry --config=/etc/sentry.conf.py repair --owner=administrator
Failed to install Celery error handler
Traceback (most recent call last):
  File "/www/sentry/lib/python2.6/site-packages/raven-3.3.6-py2.6.egg/raven/contrib/django/models.py", line 202, in register_handlers
    register_logger_signal(client)
  File "/www/sentry/lib/python2.6/site-packages/raven-3.3.6-py2.6.egg/raven/contrib/celery/__init__.py", line 60, in register_logger_signal
    handler = SentryHandler(client)
  File "/www/sentry/lib/python2.6/site-packages/raven-3.3.6-py2.6.egg/raven/handlers/logging.py", line 37, in __init__
    arg,
  File "/www/sentry/lib/python2.6/site-packages/raven-3.3.6-py2.6.egg/raven/contrib/django/models.py", line 49, in <lambda>
    __repr__ = lambda x: repr(get_client())
  File "/www/sentry/lib/python2.6/site-packages/raven-3.3.6-py2.6.egg/raven/contrib/django/models.py", line 144, in get_client
    instance = getattr(__import__(module, {}, {}, class_name), class_name)(**options)
TypeError: __init__() keywords must be strings
Assigning ownerless projects to administrator
Creating missing teams on projects
Creating missing project keys
(sentry)admin2@Dynobuntu16:~$
 
- it could be an issue with host forwarding

If I am understanding this correctly, I don't think this is happening as the firewall is ignoring the http traffic so it is just natting the connection straight through (172.16.3.6:9000 --> 192.168.1.25:9000).  No HTTP forwarding/interrogation or proxying is taking place.
 
- you might need to set SENTRY_URL_PREFIX

I already have this set:
SENTRY_URL_PREFIX = 'http://172.16.3.6:9000'

Also, I did suspect something like that to be a problem.  I used our dev environment to test this:  With the above set exactly as you see it, I tested our dev code using both of the below and they worked fine (I replaced the login details with {api_token} for security in this post):

http://{api_token}@192.168.1.25:9000/4
http://{api_token}@dynobuntu16:9000/4

1. dynobuntu16 was in the /etc/hosts file of our dev machine resolving to 192.168.1.25
2. I could not test 172.16.3.6 from our dev machine since that IP is only accessible from the other side of the firewall.

Does sentry do some kind of checking of the IP range to make sure it is on the same network? - e.g. does it interrogate 172.16.3.6 in some way to make sure a) if it is accessible    or   b) that 172.16.3.6 is set on one of the interfaces

that __init__() keywords error is concerning at the top of this post, but it does not explain why dev works and staging doesn't :(
 

To unsubscribe from this group and stop receiving emails from it, send an email to getsentry+unsubscribe@googlegroups.com.

For more options, visit https://groups.google.com/groups/opt_out.
 
 
Message has been deleted

seraph...@gmail.com

unread,
Jun 19, 2013, 7:40:46 AM6/19/13
to gets...@googlegroups.com
OK, I have been trying a few more drastic things and the results don't make sense to me yet, but I will post them here anyway to see if perhaps it makes sense to you...

I changed the rules on the firewall to stop natting and rather to route the traffic.  The 172.16.3.6 IP is now out of the equation.  I can browse http://192.168.1.25:9000/login/ directly from a browser on the staging server (i.e. exactly like dev can).  But there are still no events being logged in sentry.

1) So now Dev and Staging are:
   a) using exactly the same sentry endpoint: "http://{app_token}@192.168.1.25:9000/4"
   b) using two copies of exactly the same code from our source control
   c) using the same RavenJava compiled .jar files and the same dependencies.
2) The firewall is routing the traffic, not natting, and it is logging the acceptance of the packet thus confirming that it is routing the packets to sentry
3) I can browse sentry from the staging server
4) Dev logs entries into sentry, but staging doesn't (I have just retested both)
5) Sentry console (in terminal window) does throw some warnings, but only when testing Dev (e.g. Warning: Data truncated for column 'platform' at row 1).
6) Nothing shows on the sentry console (in terminal window) when testing from staging

Dev is running on a Mac (Java version 1.6.0_45),
Staging is running on Windows (Java version 1.6.0_17),
Sentry is installed on Ubuntu (python version 2.6.2)

Raven and Dependency Versions used on both Dev and Staging
raven, 3.0
commons-codec, 1.6
jackson-core, 2.2.0
jackson-annotations, 2.2.0
jackson-databind, 2.2.0
javax.servlet-api, 3.0.1

Here are some tcpdump's from the sentry server...

Successful Event from Dev:
12:52:54.738076 IP 192.168.1.210.65444 > 192.168.1.25.9000: S 3423623473:3423623473(0) win 65535 <mss 1460,nop,wscale 4,nop,nop,timestamp 644654537 0,sackOK,eol>
12:52:54.738088 IP 192.168.1.25.9000 > 192.168.1.210.65444: S 4285953545:4285953545(0) ack 3423623474 win 5792 <mss 1460,sackOK,timestamp 888903025 644654537,nop,wscale 7>
12:52:54.738477 IP 192.168.1.210.65444 > 192.168.1.25.9000: . ack 1 win 8235 <nop,nop,timestamp 644654537 888903025>
12:52:54.739624 IP 192.168.1.210.65444 > 192.168.1.25.9000: P 1:402(401) ack 1 win 8235 <nop,nop,timestamp 644654538 888903025>
12:52:54.739635 IP 192.168.1.210.65444 > 192.168.1.25.9000: . 402:1850(1448) ack 1 win 8235 <nop,nop,timestamp 644654538 888903025>
12:52:54.739638 IP 192.168.1.210.65444 > 192.168.1.25.9000: . 1850:3298(1448) ack 1 win 8235 <nop,nop,timestamp 644654538 888903025>
12:52:54.739640 IP 192.168.1.210.65444 > 192.168.1.25.9000: . 3298:4381(1083) ack 1 win 8235 <nop,nop,timestamp 644654538 888903025>
12:52:54.739646 IP 192.168.1.25.9000 > 192.168.1.210.65444: . ack 402 win 54 <nop,nop,timestamp 888903025 644654538>
12:52:54.739658 IP 192.168.1.25.9000 > 192.168.1.210.65444: . ack 1850 win 77 <nop,nop,timestamp 888903025 644654538>
12:52:54.739663 IP 192.168.1.25.9000 > 192.168.1.210.65444: . ack 3298 win 99 <nop,nop,timestamp 888903025 644654538>
12:52:54.739668 IP 192.168.1.25.9000 > 192.168.1.210.65444: . ack 4381 win 122 <nop,nop,timestamp 888903025 644654538>
12:52:54.740272 IP 192.168.1.210.65444 > 192.168.1.25.9000: P 4381:5798(1417) ack 1 win 8235 <nop,nop,timestamp 644654539 888903025>
12:52:54.740283 IP 192.168.1.25.9000 > 192.168.1.210.65444: . ack 5798 win 145 <nop,nop,timestamp 888903025 644654539>
12:52:54.783116 IP 192.168.1.25.9000 > 192.168.1.210.65444: P 1:337(336) ack 5798 win 145 <nop,nop,timestamp 888903029 644654539>
12:52:54.783173 IP 192.168.1.25.9000 > 192.168.1.210.65444: P 337:342(5) ack 5798 win 145 <nop,nop,timestamp 888903029 644654539>
12:52:54.783242 IP 192.168.1.25.9000 > 192.168.1.210.65444: F 342:342(0) ack 5798 win 145 <nop,nop,timestamp 888903029 644654539>
12:52:54.783603 IP 192.168.1.210.65444 > 192.168.1.25.9000: . ack 337 win 8214 <nop,nop,timestamp 644654582 888903029>
12:52:54.783616 IP 192.168.1.210.65444 > 192.168.1.25.9000: . ack 342 win 8214 <nop,nop,timestamp 644654582 888903029>
12:52:54.783702 IP 192.168.1.210.65444 > 192.168.1.25.9000: . ack 343 win 8214 <nop,nop,timestamp 644654582 888903029>
12:52:54.805765 IP 192.168.1.210.65444 > 192.168.1.25.9000: F 5798:5798(0) ack 343 win 8214 <nop,nop,timestamp 644654602 888903029>
12:52:54.805778 IP 192.168.1.25.9000 > 192.168.1.210.65444: . ack 5799 win 145 <nop,nop,timestamp 888903032 644654602>
12:52:56.919000 IP 192.168.1.4.137 > 192.168.1.255.137: NBT UDP PACKET(137): QUERY; REQUEST; BROADCAST


Ignored Event from Staging using FW routing:
12:51:10.313869 IP 192.168.3.20.60379 > 192.168.1.25.9000: S 3914518643:3914518643(0) win 8192 <mss 1460,nop,wscale 8,nop,nop,sackOK>
12:51:10.313886 IP 192.168.1.25.9000 > 192.168.3.20.60379: S 2638134472:2638134472(0) ack 3914518644 win 5840 <mss 1460,nop,nop,sackOK,nop,wscale 7>
12:51:10.326501 IP 192.168.3.20.60379 > 192.168.1.25.9000: . ack 1 win 256
12:51:10.327995 IP 192.168.3.20.60379 > 192.168.1.25.9000: F 1:1(0) ack 1 win 256
12:51:10.328092 IP 192.168.1.25.9000 > 192.168.3.20.60379: F 1:1(0) ack 2 win 46
12:51:10.340576 IP 192.168.3.20.60379 > 192.168.1.25.9000: . ack 2 win 256

Ignored Event from Staging using FW port forwarding:
12:56:12.224620 IP 192.168.3.20.60401 > 192.168.1.25.9000: S 4152708382:4152708382(0) win 8192 <mss 1460,nop,wscale 8,nop,nop,sackOK>
12:56:12.224655 IP 192.168.1.25.9000 > 192.168.3.20.60401: S 3067581795:3067581795(0) ack 4152708383 win 5840 <mss 1460,nop,nop,sackOK,nop,wscale 7>
12:56:12.237300 IP 192.168.3.20.60401 > 192.168.1.25.9000: . ack 1 win 256
12:56:12.238798 IP 192.168.3.20.60401 > 192.168.1.25.9000: F 1:1(0) ack 1 win 256
12:56:12.238886 IP 192.168.1.25.9000 > 192.168.3.20.60401: F 1:1(0) ack 2 win 46
12:56:12.251027 IP 192.168.3.20.60401 > 192.168.1.25.9000: . ack 2 win 256

Ignored Event from Staging using FW port forwarding with Source Natting (192.168.1.14 is the FW):
13:36:33.171039 IP 192.168.1.14.60594 > 192.168.1.25.9000: S 3640390344:3640390344(0) win 8192 <mss 1460,nop,wscale 8,nop,nop,sackOK>
13:36:33.171065 IP 192.168.1.25.9000 > 192.168.1.14.60594: S 2379536534:2379536534(0) ack 3640390345 win 5840 <mss 1460,nop,nop,sackOK,nop,wscale 7>
13:36:33.185415 IP 192.168.1.14.60594 > 192.168.1.25.9000: . ack 1 win 256
13:36:33.186914 IP 192.168.1.14.60594 > 192.168.1.25.9000: F 1:1(0) ack 1 win 256
13:36:33.186975 IP 192.168.1.25.9000 > 192.168.1.14.60594: F 1:1(0) ack 2 win 46
13:36:33.209876 IP 192.168.1.14.60594 > 192.168.1.25.9000: . ack 2 win 256

That last one excludes the possibility that the IP range could be causing the problem.

I even checked the gunicorn config options and added:

    'forwarded_allow_ips': '*',
    'proxy_allow_ips': '*',
    'accesslog':'/var/log/sentry_access.log',
    'errorlog':'/var/log/sentry_error.log',
 
and nothing shows up in those logs for dev or staging.

I'm at a loss.

seraph...@gmail.com

unread,
Jun 19, 2013, 8:30:35 AM6/19/13
to gets...@googlegroups.com
Hi Guys,

We found the problem.  Raven-java is running inside coldfusion.  On Dev, our code uses a custom classloader to manage .jar dependencies for coldfusion and auto-fetch form nexus, etc.  On staging and Live, we rollout the jar files manually and allow coldfusion's classloader to do the work.  This was the difference that was causing the problem.  Raven was dumping the following error in the Coldfusion Console on staging:

Exception in thread "pool-8-thread-34" java.lang.VerifyError: (class: org/apache/commons/codec/binary/Base64OutputStream, method: <init> signature: (Ljava/io/OutputStream;ZI[B)V) Incompatible argument to function
    at net.kencochrane.raven.marshaller.json.JsonMarshaller.marshall(JsonMarshaller.java:95)
    at net.kencochrane.raven.connection.HttpConnection.doSend(HttpConnection.java:103)
    at net.kencochrane.raven.connection.AbstractConnection.send(AbstractConnection.java:78)
    at net.kencochrane.raven.connection.AsyncConnection$EventSubmitter.run(AsyncConnection.java:139)
    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
    at java.lang.Thread.run(Thread.java:619)

Making it use our classloader solved the problem.  Both dev and staging are using the same commons-codec version (1.6).

Unfortunately our classloader was only designed for Dev purposes, so it has not been tested in a live environment and we are going to have to figure out how to get Coldfusion's classloader to behave.  But now at least we have a difinitive problem to tackle and resolve.  Thanks for your help David, if you have any ideas, please share.  When we figure it out, I will post our solution here.

Cheers,
Seraph


On Wednesday, June 19, 2013 10:18:33 AM UTC+2, seraph...@gmail.com wrote:
Message has been deleted

seraph...@gmail.com

unread,
Jun 19, 2013, 10:07:57 AM6/19/13
to gets...@googlegroups.com
Fixed.  one of the third party jar files (adwords-api-8.0.0.jar) included the class files of commons-codec-1.3 which was causing the problem.  It was a fat jar.

Complicated debugging, simple solution... Gotta love a programmer's job :)

I hope this thread is able to help others.

Here is the Coldfusion code I used to dump all the classes loaded by the CF Classloader and the jars that contain them:

<cffunction name="output">
    <cfargument name="str" />
    <cfoutput>#str#</cfoutput>
</cffunction>
<cffunction name="dump">
    <cfargument name="vr" />
    <cfdump var="#vr#">
</cffunction>
<cffunction name="abort">
    <cfabort>
</cffunction>

<cfscript>
    byClassLoader = getPageContext().getClass().getClassLoader();
    clKlass = byClassLoader.getClass();
    output("Classloader: " & clKlass.getCanonicalName() & "<br />");
    cl = CreateObject("java", "java.lang.ClassLoader");
    while (clKlass NEQ cl.getClass()) {
        clKlass = clKlass.getSuperclass();
    }

    fldClasses = clKlass.getDeclaredField("classes");
    fldClasses.setAccessible(true);
    classes = fldClasses.get(byClassLoader);
    for (iter = classes.iterator(); iter.hasNext();) {
        className = iter.next();
        output("&nbsp;&nbsp;&nbsp;Loaded " & className & "<br />");
        jarFiles = byClassLoader.getResources(Replace(ListLast(className, " "), ".", "/", "ALL") & ".class");
        while (jarFiles.hasMoreElements()){
            jarFile = jarFiles.nextElement();
            output("&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; " & jarFile.toString() & "<br />");
        }
    }
</cfscript>


On Wednesday, June 19, 2013 10:18:33 AM UTC+2, seraph...@gmail.com wrote:
Reply all
Reply to author
Forward
0 new messages