2015-05-05 11 views
18

Ich habe eine Ruby on Rails-Anwendung auf Heroku ausgeführt. Ich bekomme diese Meldungen im Log:Meine App erstellt Datenbankverbindungen, wie kann ich den Grund ermitteln?

2015-05-05T16:11:14Z app[postgres.27102]: [AQUA] connection received: host=xx.xxx.xx.26 port=60278 
2015-05-05T16:11:14Z app[postgres.27102]: [AQUA] connection authorized: user=postgres database=somedb 
2015-05-05T16:11:14Z app[postgres.27103]: [AQUA] connection received: host=xx.xxx.xx.26 port=60291 
2015-05-05T16:11:14Z app[postgres.27103]: [AQUA] connection authorized: user=postgres database=postgres 
2015-05-05T16:11:18Z app[postgres.27104]: [AQUA] connection received: host=xx.xxx.x.166 port=54180 
2015-05-05T16:11:18Z app[postgres.27104]: [AQUA] connection authorized: user=postgres database=somedb 
2015-05-05T16:11:23Z app[postgres.27105]: [AQUA] connection received: host=xx.xxx.x.166 port=55488 
2015-05-05T16:11:23Z app[postgres.27105]: [AQUA] connection authorized: user=postgres database=somedb 
2015-05-05T16:11:28Z app[postgres.27106]: [AQUA] connection received: host=xx.xxx.x.166 port=56774 
2015-05-05T16:11:28Z app[postgres.27106]: [AQUA] connection authorized: user=postgres database=somedb 
2015-05-05T16:11:28Z app[postgres.27107]: [AQUA] connection received: host=xx.xxx.x.166 port=56854 
2015-05-05T16:11:28Z app[postgres.27107]: [AQUA] connection authorized: user=postgres database=somedb 
2015-05-05T16:11:28Z app[postgres.27108]: [AQUA] connection received: host=xx.xxx.x.166 port=56885 
2015-05-05T16:11:28Z app[postgres.27108]: [AQUA] connection authorized: user=postgres database=somedb 
2015-05-05T16:11:28Z app[postgres.27109]: [AQUA] connection received: host=xx.xxx.x.166 port=56912 
2015-05-05T16:11:28Z app[postgres.27109]: [AQUA] connection authorized: user=postgres database=somedb 
2015-05-05T16:11:33Z app[postgres.27110]: [AQUA] connection received: host=xx.xxx.x.166 port=58039 
2015-05-05T16:11:33Z app[postgres.27110]: [AQUA] connection authorized: user=postgres database=somedb 
2015-05-05T16:11:38Z app[postgres.27111]: [AQUA] connection received: host=xx.xxx.x.166 port=59387 
2015-05-05T16:11:38Z app[postgres.27111]: [AQUA] connection authorized: user=postgres database=somedb 
2015-05-05T16:11:43Z app[postgres.27112]: [AQUA] connection received: host=xx.xxx.x.166 port=60944 
2015-05-05T16:11:43Z app[postgres.27112]: [AQUA] connection authorized: user=postgres database=somedb 
2015-05-05T16:11:14+00:00 app[heroku-postgres]: source=HEROKU_POSTGRESQL_AQUA sample#current_transaction=511990 sample#db_size=203303096bytes sample#tables=17 sample#active-connections=2 sample#waiting-connections=0 sample#index-cache-hit-rate=0.99997 sample#table-cache-hit-rate=0.94699 sample#load-avg-1m=0.14 sample#load-avg-5m=0.25 sample#load-avg-15m=0.24 sample#read-iops=0.1875 sample#write-iops=1 sample#memory-total=7629448kB sample#memory-free=428388kB sample#memory-cached=6784860kB sample#memory-postgres=171732kB 

Ich kann nicht herausfinden, was das verursacht. Die Anwendung läuft Cedar 10 Stapel, Ruby 2.1.4, Schienen 3.2.11 und Puma 2.11.2 mit 3 Arbeiter und 1 Faden. Es passiert nicht in den Entwicklungs- oder Staging-Umgebungen, nur auf Heroku.

Laufen: select application_name from pg_stat_activity; zeigt:

 application_name   
--------------------------------- 

puma: cluster worker 2: 3 [app] 
puma: cluster worker 1: 3 [app] 
puma: cluster worker 0: 3 [app] 
psql johnny interactive 

hier ist meine puma-Konfigurationsdatei (min und max Gewinde ist gleich 1):

workers Integer(ENV['PUMA_WORKERS'] || 3) 
threads Integer(ENV['MIN_THREADS'] || 1), Integer(ENV['MAX_THREADS'] || 16) 

preload_app! 

rackup  DefaultRackup 
port  ENV['PORT']  || 3000 
environment ENV['RACK_ENV'] || 'development' 

on_worker_boot do 
    # worker specific setup 
    ActiveSupport.on_load(:active_record) do 
    config = ActiveRecord::Base.configurations[Rails.env] || 
       Rails.application.config.database_configuration[Rails.env] 
    config['pool'] = ENV['MAX_THREADS'] || 16 
    ActiveRecord::Base.establish_connection(config) 
    end 
end 

Alle Ideen, wie dies zu verfolgen?

aktualisieren: Ich habe eine Debug-Nachricht an den on_worker_boot Block und es wird nur auf den Start der Anwendung aufgerufen, so habe ich immer noch keine Ahnung, warum Verbindungen Wesen so häufig etabliert.

+0

Es könnte ein Add-on sein, das diese Verbindungen herstellt. Welche Add-ons haben Sie installiert? – infused

+0

Postgres, Mandrill, neues Relikt, Papertrail, PG Backups, RedisToGo und Heroku Scheduler. – Johnny

+0

Ein paar Fragen in den Sinn kommen - 1) Was (wenn überhaupt) planen Sie? 2) Gibt es einen Gesundheitscheck von New Relic, der (ungefähr) der Häufigkeit entspricht? – bimsapi

Antwort

4

Dies ist Casual Logs über Verbindung zu Postgres. Also, ignorieren Sie sie einfach oder versuchen Sie sie in postgresql.conf zu deaktivieren (siehe log_connections Option), aber ich glaube nicht, dass Sie in Heroku Zugriff darauf haben.

+0

Ich glaube nicht, dass es das ist. Wenn Sie sich die Protokolle ansehen, werden mehrere Male pro Sekunde Verbindungen erstellt. So sollte es nicht sein. – Johnny

+0

Ist dieser Beginn des Protokolls oder Sie sehen solche Protokollmeldungen nach mehreren Minuten der Anwendung arbeiten? Im ersten Fall kann es verwandt werden, um Puma-Arbeiter zu starten, im zweiten Fall ist das ein Problem. – willis

+0

Es ist ziemlich kontinuierlich. – Johnny

0

Nicht mit Heroku gearbeitet, aber haben Sie versucht, einen Thread-Dump des Rubinprozesses mit einem Werkzeug wie Xray zu bekommen? http://blog.pivotal.io/labs/labs/inspect-running-ruby-processes-using-xray-and-kill-3

Der Thread-Stapel kann helfen, die Quelle dieser Aufrufe anzuzeigen.

+0

Hier sind die Ergebnisse des Thread-Dumps: http://dumptext.com/piqHWgAq. Nicht wirklich sicher, wie man das interpretiert. – Johnny

+0

Ich weiß nicht, was in der Spur falsch ist. Höchstwahrscheinlich ist der Worker aufgrund eines Fehlers abgestürzt und wird neu gestartet. Jemand kenntnisreicher kann hier helfen. – codedabbler

Verwandte Themen