Spamsnake Ubuntu 12.04 - 504 Timeout

Discussion in 'HOWTO-Related Questions' started by JhonKa, Jan 3, 2013.

  1. JhonKa

    JhonKa New Member

    Hello,

    After some issues, I finally got SpamSnake setup completely. I was testing the spam filter before I put it in production and noticed that after I either learn/preview message/delete a message from baruwa, the web server will stop responding and I get a 504 Timed out. The issue will resolve itself If I reboot the server, however it comes right back when I preview a message in the quarantine.

    In the nginx error.log I am seeing this:

    2013/01/03 09:38:49 [error] 2525#0: *167 upstream timed out (110: Connection timed out) while reading response header from upstream, client: (hidden), server: (hidden), request: "GET / HTTP/1.1", upstream: "uwsgi://unix:///var/run/uwsgi/app/baruwa/socket:", host: "(hidden)"

    Do you guys have any ideas?
     
    Last edited: Jan 3, 2013
  2. Rocky

    Rocky Member

    Try running baruwa-admin migrate djcelery, reboot and see what happens
     
  3. JhonKa

    JhonKa New Member

    Thank you Rocky for the response! Unfortunately that didn't help at all. When I click Preview message it still just times out.

    FWIW this is what happened when I ran the command:


    Running migrations for djcelery:
    - Nothing to migrate.
    - Loading initial data for djcelery.
    No fixtures found.
     
  4. Rocky

    Rocky Member

    Post your baruwa and uwsgi logs
     
  5. JhonKa

    JhonKa New Member

    Sorry about the long wait, I was out of town for the weekend.

    My celeryd.log is here:


    ---- **** -----
    --- * *** * -- [Configuration]
    -- * - **** --- . broker: amqp://password@localhost:5672/baruwa
    - ** ---------- . loader: djcelery.loaders.DjangoLoader
    - ** ---------- . logfile: /var/log/baruwa/celeryd.log@INFO
    - ** ---------- . concurrency: 2
    - ** ---------- . events: ON
    - *** --- * --- . beat: ON
    -- ******* ----
    --- ***** ----- [Queues]
    -------------- . default: exchange:default (direct) binding:default
    . gw3: exchange:default (direct) binding:gw3

    [Tasks]
    . delete-domain-signature-files
    . delete-user-signature-files
    . generate-domain-signature-files
    . generate-user-signature-files
    . preview-message
    . process-quarantine
    . process-quarantined-msg
    . release-message
    . test-smtp-server
    [2013-01-07 10:37:19,259: INFO/PoolWorker-2] child process calling self.run()
    [2013-01-07 10:37:19,267: INFO/PoolWorker-3] child process calling self.run()
    [2013-01-07 10:37:19,277: INFO/Beat] child process calling self.run()
    [2013-01-07 10:37:19,276: WARNING/MainProcess] celery@gw3 has started.
    [2013-01-07 10:37:19,278: INFO/Beat] Celerybeat: Starting...
    [2013-01-07 10:38:27,782: INFO/MainProcess] Got task from broker: preview-message[9261023c-4292-423c-a4cf-98e6469859ce]
    [2013-01-07 10:38:27,840: INFO/PoolWorker-3] preview-message[9261023c-4292-423c-a4cf-98e6469859ce]: Preview of message: 27CD8C0DF7.AB05F requested by user:
    [2013-01-07 10:38:27,854: INFO/MainProcess] Task preview-message[9261023c-4292-423c-a4cf-98e6469859ce] succeeded in 0.0686628818512s: {'headers': {'date': u'Mon, 07 Jan 2013...

    As you can see it "successfully" previews the message.

    uswgi logs:

    [uWSGI] getting INI configuration from /usr/share/uwsgi/conf/default.ini
    [uWSGI] getting INI configuration from /etc/uwsgi/apps-enabled/baruwa.ini
    Mon Jan 7 10:07:56 2013 - option "module" found in plugin python27_plugin.so
    Mon Jan 7 10:07:56 2013 - *** Starting uWSGI 1.0.3-debian (64bit) on [Mon Jan 7 10:07:56 2013] ***
    Mon Jan 7 10:07:56 2013 - compiled with version: 4.6.3 on 17 July 2012 02:26:54
    Mon Jan 7 10:07:56 2013 - current working directory: /
    Mon Jan 7 10:07:56 2013 - writing pidfile to /run/uwsgi/app/baruwa/pid
    Mon Jan 7 10:07:56 2013 - detected binary path: /usr/bin/uwsgi-core
    Mon Jan 7 10:07:56 2013 - *** WARNING: you are running uWSGI as root !!! (use the --uid flag) ***
    Mon Jan 7 10:07:56 2013 - your memory page size is 4096 bytes
    Mon Jan 7 10:07:56 2013 - uwsgi socket 0 bound to UNIX address /run/uwsgi/app/baruwa/socket fd 5
    Mon Jan 7 10:07:56 2013 - Python version: 2.7.3 (default, Aug 1 2012, 05:25:23) [GCC 4.6.3]
    Mon Jan 7 10:07:57 2013 - Python main interpreter initialized at 0x2169870

    And when I hit "preview message" in Baruwa this pops up in the uwsgi log.

    /usr/lib/python2.7/dist-packages/djcelery/managers.py:173: TxIsolationWarning: Polling results with transaction isolation level repeatable-read within the same transaction may give outdated results. Be sure to commit the transaction for each poll iteration.
    "Polling results with transaction isolation level "
     
    Last edited: Jan 7, 2013
  6. JhonKa

    JhonKa New Member

    I ripped out nginx & uwsgi and installed apache2. I was able to get into the web interface but I am still running into the same issues. I guess that means we can rule out the web server portion as the culprit.

    EDIT: It looks like it doesn't 504 (possibly due to longer timeout times?) . I can also get back to the main page! When I tried it on nginx, baruwa would just lock up and i would have to restart the service.
     
    Last edited: Jan 8, 2013
  7. JhonKa

    JhonKa New Member

    Rocky,

    I've discovered that rabbitmq closes the AMQP connection when i click on "preview message"

    rabbitmq log:

    =INFO REPORT==== 9-Jan-2013::13:50:38 ===
    accepting AMQP connection <0.247.0> (127.0.0.1:55015 -> 127.0.0.1:5672)

    then it shows this next message when i click "preview message"

    =INFO REPORT==== 9-Jan-2013::13:50:38 ===
    closing AMQP connection <0.247.0> (127.0.0.1:55015 -> 127.0.0.1:5672)
     
  8. Rocky

    Rocky Member

    Try reinstalling rabbitmq:

    apt-get install rabbitmq-server

    Restart and let me know what happens.
     
  9. JhonKa

    JhonKa New Member

    I found out that rabbitmq closes and opens a new connection for everything. So nothing is wrong with that. I did try to uninstall rabbitmq-server yesterday along with purging all the config files. Still no luck...

    Are there any other logs i can post?
     
  10. jrossi90

    jrossi90 New Member

    *bump
    I am having the same issue. After I completed the install, everything worked great (including the preview and quarantine functions). After a reboot, I get the same issue described above. I can provide a little more insight - in the /var/log/uwsgi/app/baruwa.log I see the following right before it crashes:

    Error opening file for reading: Permission denied
    [pid: 2983|app: 0|req: 1/1] 10.10.10.16 () {40 vars in 853 bytes} [Fri May 17 21:53:25 2013] GET /messages/ => generated 2555 bytes in 519 msecs (HTTP/1.1 200) 6 headers in 297 bytes (1 switches on core 0)
    [pid: 2984|app: 0|req: 1/2] 10.10.10.16 () {40 vars in 715 bytes} [Fri May 17 21:53:26 2013] GET /jsi18n/ => generated 2158 bytes in 224 msecs (HTTP/1.1 200) 2 headers in 72 bytes (1 switches on core 0)
    Error opening file for reading: Permission denied
    [pid: 2984|app: 0|req: 2/3] 10.10.10.16 () {40 vars in 876 bytes} [Fri May 17 21:53:29 2013] GET /messages/view/9B8C2B40E7E.A3BB4/ => generated 4204 bytes in 319 msecs (HTTP/1.1 200) 6 headers in 297 bytes (1 switches on core 0)
    [pid: 2984|app: 0|req: 3/4] 10.10.10.16 () {40 vars in 738 bytes} [Fri May 17 21:53:30 2013] GET /jsi18n/ => generated 2158 bytes in 4 msecs (HTTP/1.1 200) 2 headers in 72 bytes (1 switches on core 0)


    Any help would be greatly appreciated.

    P.S Great howto, Rocky!
     
  11. jrossi90

    jrossi90 New Member

    FYI - For all those who are having the same or similar problem. This is due to Ubuntu Bug #1031718 with a Ubuntu update.

    The patch adds some auxv related stuff to the library init that attempt to read /proc/self/auxv. If it fails the above error is printed usually ending up to application's log that's using the library. Looking at the log it's completely unclear where that error came from and what file was it trying to read.

    The /proc/self/auxv has 0400 permissions and is owned by the user who started the process. If the process drops privileges and setuid()'s to another user, the file is no longer readable.


    To fix, add:
    setuid uwsgiuser
    setgid uwsgiuser


    To the .ini of the application.

    - jrossi90
     
  12. jrossi90

    jrossi90 New Member

    The fix I mentioned earlier seems to not have fully resolved the problem as the issue has returned.
    Can anyone help?
    -jrossi90
     

Share This Page