PostgreSQL se cierra después de iniciarse

9

Mi servidor PostgreSQL 9.5 en Debian 8 (Jessie) sigue saliendo directamente después de iniciarse a través de service postgresql start:

# service postgresql status
● postgresql.service - PostgreSQL RDBMS
   Loaded: loaded (/lib/systemd/system/postgresql.service; enabled)
   Active: active (exited) since Fr 2016-12-02 11:02:51 CET; 11min ago
  Process: 2360 ExecStart=/bin/true (code=exited, status=0/SUCCESS)
 Main PID: 2360 (code=exited, status=0/SUCCESS)
   CGroup: /system.slice/postgresql.service

Dez 05 16:29:24 dev systemd[1]: Starting PostgreSQL RDBMS...
Dez 05 16:29:24 dev systemd[1]: Started PostgreSQL RDBMS.

Tenga en cuenta el active (exited)estado. El servidor está inactivo, por ejemplo, no puedo conectarme a él a través de TCP o socket de dominio, y no puedo encontrar ningún proceso asociado.

Sin embargo, cuando inicio PostgreSQL manualmente , funciona:

# sudo -u postgres /usr/lib/postgresql/9.5/bin/postgres -d 3 -D /var/lib/postgresql/9.5/main/ -c config_file=/etc/postgresql/9.5/main/postgresql.conf 

2016-12-05 16:34:32 CET [1593-1] DEBUG:  postgres: PostmasterMain: initial environment dump:
2016-12-05 16:34:32 CET [1593-2] DEBUG:  -----------------------------------------
2016-12-05 16:34:32 CET [1593-3] DEBUG:     LC_PAPER=de_DE.UTF-8
2016-12-05 16:34:32 CET [1593-4] DEBUG:     LC_ADDRESS=de_DE.UTF-8
2016-12-05 16:34:32 CET [1593-5] DEBUG:     LC_MONETARY=C
2016-12-05 16:34:32 CET [1593-6] DEBUG:     TERM=xterm-256color
2016-12-05 16:34:32 CET [1593-7] DEBUG:     LC_NUMERIC=C
2016-12-05 16:34:32 CET [1593-8] DEBUG:     LC_TELEPHONE=de_DE.UTF-8
2016-12-05 16:34:32 CET [1593-9] DEBUG:     LS_COLORS=rs=0:di=01;34:ln=01;36:mh=00:pi=40;33:so=01;35:do=01;35:bd=40;33;01:cd=40;33;01:or=40;31;01:su=37;41:sg=30;43:ca=30;41:tw=30;42:ow=34;42:st=37;44:ex=01;32:*.tar=01;31:*.tgz=01;31:*.arc=01;31:*.arj=01;31:*.taz=01;31:*.lha=01;31:*.lz4=01;31:*.lzh=01;31:*.lzma=01;31:*.tlz=01;31:*.txz=01;31:*.tzo=01;31:*.t7z=01;31:*.zip=01;31:*.z=01;31:*.Z=01;31:*.dz=01;31:*.gz=01;31:*.lrz=01;31:*.lz=01;31:*.lzo=01;31:*.xz=01;31:*.bz2=01;31:*.bz=01;31:*.tbz=01;31:*.tbz2=01;31:*.tz=01;31:*.deb=01;31:*.rpm=01;31:*.jar=01;31:*.war=01;31:*.ear=01;31:*.sar=01;31:*.rar=01;31:*.alz=01;31:*.ace=01;31:*.zoo=01;31:*.cpio=01;31:*.7z=01;31:*.rz=01;31:*.cab=01;31:*.jpg=01;35:*.jpeg=01;35:*.gif=01;35:*.bmp=01;35:*.pbm=01;35:*.pgm=01;35:*.ppm=01;35:*.tga=01;35:*.xbm=01;35:*.xpm=01;35:*.tif=01;35:*.tiff=01;35:*.png=01;35:*.svg=01;35:*.svgz=01;35:*.mng=01;35:*.pcx=01;35:*.mov=01;35:*.mpg=01;35:*.mpeg=01;35:*.m2v=01;35:*.mkv=01;35:*.webm=01;35:*.ogm=01;35:*.mp4=01;35:*.m4v=01;35:*.mp4v=01;35:*.vob=01;35:*.qt=01;35:*.nuv=01;35:*.wmv=01;35:*.asf=01;35:*.rm=01;35:*.rmvb=01;35:*.flc=01;35:*.avi=01;35:*.fli=01;35:*.flv=01;35:*.gl=01;35:*.dl=01;35:*.xcf=01;35:*.xwd=01;35:*.yuv=01;35:*.cgm=01;35:*.emf=01;35:*.axv=01;35:*.anx=01;35:*.ogv=01;35:*.ogx=01;35:*.aac=00;36:*.au=00;36:*.flac=00;36:*.m4a=00;36:*.mid=00;36:*.midi=00;36:*.mka=00;36:*.mp3=00;36:*.mpc=00;36:*.ogg=00;36:*.ra=00;36:*.wav=00;36:*.axa=00;36:*.oga=00;36:*.spx=00;36:*.xspf=00;36:
2016-12-05 16:34:32 CET [1593-10] DEBUG:    PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
2016-12-05 16:34:32 CET [1593-11] DEBUG:    LC_IDENTIFICATION=de_DE.UTF-8
2016-12-05 16:34:32 CET [1593-12] DEBUG:    LANG=en_US.UTF-8
2016-12-05 16:34:32 CET [1593-13] DEBUG:    LC_MEASUREMENT=de_DE.UTF-8
2016-12-05 16:34:32 CET [1593-14] DEBUG:    LC_TIME=C
2016-12-05 16:34:32 CET [1593-15] DEBUG:    LC_NAME=de_DE.UTF-8
2016-12-05 16:34:32 CET [1593-16] DEBUG:    SHELL=/bin/bash
2016-12-05 16:34:32 CET [1593-17] DEBUG:    MAIL=/var/mail/postgres
2016-12-05 16:34:32 CET [1593-18] DEBUG:    LOGNAME=postgres
2016-12-05 16:34:32 CET [1593-19] DEBUG:    USER=postgres
2016-12-05 16:34:32 CET [1593-20] DEBUG:    USERNAME=postgres
2016-12-05 16:34:32 CET [1593-21] DEBUG:    HOME=/var/lib/postgresql
2016-12-05 16:34:32 CET [1593-22] DEBUG:    SUDO_COMMAND=/usr/lib/postgresql/9.5/bin/postgres -d 3 -D /var/lib/postgresql/9.5/main/ -c config_file=/etc/postgresql/9.5/main/postgresql.conf
2016-12-05 16:34:32 CET [1593-23] DEBUG:    SUDO_USER=root
2016-12-05 16:34:32 CET [1593-24] DEBUG:    SUDO_UID=0
2016-12-05 16:34:32 CET [1593-25] DEBUG:    SUDO_GID=0
2016-12-05 16:34:32 CET [1593-26] DEBUG:    PGLOCALEDIR=/usr/share/locale
2016-12-05 16:34:32 CET [1593-27] DEBUG:    PGSYSCONFDIR=/etc/postgresql-common
2016-12-05 16:34:32 CET [1593-28] DEBUG:    LC_COLLATE=en_US.UTF-8
2016-12-05 16:34:32 CET [1593-29] DEBUG:    LC_CTYPE=en_US.UTF-8
2016-12-05 16:34:32 CET [1593-30] DEBUG:    LC_MESSAGES=en_US.UTF-8
2016-12-05 16:34:32 CET [1593-31] DEBUG:  -----------------------------------------
2016-12-05 16:34:32 CET [1593-32] DEBUG:  invoking IpcMemoryCreate(size=23887872)
2016-12-05 16:34:32 CET [1593-33] DEBUG:  mmap(25165824) with MAP_HUGETLB failed, huge pages disabled: Cannot allocate memory
2016-12-05 16:34:32 CET [1593-34] DEBUG:  SlruScanDirectory invoking callback on pg_notify/0000
2016-12-05 16:34:32 CET [1593-35] DEBUG:  removing file "pg_notify/0000"
2016-12-05 16:34:32 CET [1593-36] DEBUG:  dynamic shared memory system will support 288 segments
2016-12-05 16:34:32 CET [1593-37] DEBUG:  created dynamic shared memory control segment 1173813643 (2316 bytes)
2016-12-05 16:34:32 CET [1593-38] DEBUG:  max_safe_fds = 983, usable_fds = 1000, already_open = 7
2016-12-05 16:34:32 CET [1593-39] LOG:  redirecting log output to logging collector process
2016-12-05 16:34:32 CET [1593-40] HINT:  Future log output will appear in directory "/var/log/postgresql".

(server is now up and running and can be connected to)

Los registros /var/log/postgresqlno contienen nada sospechoso. Aquí está la salida para una ejecución manual de trabajo:

2016-12-05 16:48:07 CET [1700-1] LOG:  database system was shut down at 2016-12-05 16:36:04 CET
2016-12-05 16:48:07 CET [1700-2] DEBUG:  checkpoint record is at 0/13823548
2016-12-05 16:48:07 CET [1700-3] DEBUG:  redo record is at 0/13823548; shutdown TRUE
2016-12-05 16:48:07 CET [1700-4] DEBUG:  next transaction ID: 0/14019; next OID: 35693
2016-12-05 16:48:07 CET [1700-5] DEBUG:  next MultiXactId: 1; next MultiXactOffset: 0
2016-12-05 16:48:07 CET [1700-6] DEBUG:  oldest unfrozen transaction ID: 617, in database 1
2016-12-05 16:48:07 CET [1700-7] DEBUG:  oldest MultiXactId: 1, in database 1
2016-12-05 16:48:07 CET [1700-8] DEBUG:  commit timestamp Xid oldest/newest: 0/0
2016-12-05 16:48:07 CET [1700-9] DEBUG:  transaction ID wrap limit is 2147484264, limited by database with OID 1
2016-12-05 16:48:07 CET [1700-10] DEBUG:  MultiXactId wrap limit is 2147483648, limited by database with OID 1
2016-12-05 16:48:07 CET [1700-11] DEBUG:  starting up replication slots
2016-12-05 16:48:07 CET [1700-12] DEBUG:  MultiXactId wrap limit is 2147483648, limited by database with OID 1
2016-12-05 16:48:07 CET [1700-13] LOG:  MultiXact member wraparound protections are now enabled
2016-12-05 16:48:07 CET [1700-14] DEBUG:  MultiXact member stop limit is now 4294914944 based on MultiXact 1
2016-12-05 16:48:07 CET [1700-15] DEBUG:  shmem_exit(0): 1 before_shmem_exit callbacks to make
2016-12-05 16:48:07 CET [1700-16] DEBUG:  shmem_exit(0): 3 on_shmem_exit callbacks to make
2016-12-05 16:48:07 CET [1700-17] DEBUG:  proc_exit(0): 2 callbacks to make
2016-12-05 16:48:07 CET [1700-18] DEBUG:  exit(0)
2016-12-05 16:48:07 CET [1700-19] DEBUG:  shmem_exit(-1): 0 before_shmem_exit callbacks to make
2016-12-05 16:48:07 CET [1700-20] DEBUG:  shmem_exit(-1): 0 on_shmem_exit callbacks to make
2016-12-05 16:48:07 CET [1700-21] DEBUG:  proc_exit(-1): 0 callbacks to make
2016-12-05 16:48:07 CET [1698-41] LOG:  database system is ready to accept connections
2016-12-05 16:48:07 CET [1705-1] DEBUG:  removing permanent stats file "pg_stat/db_12381.stat"
2016-12-05 16:48:07 CET [1704-1] LOG:  autovacuum launcher started
2016-12-05 16:48:07 CET [1704-2] DEBUG:  InitPostgres
2016-12-05 16:48:07 CET [1705-2] DEBUG:  removing permanent stats file "pg_stat/db_0.stat"
2016-12-05 16:48:07 CET [1704-3] DEBUG:  StartTransaction
2016-12-05 16:48:07 CET [1705-3] DEBUG:  removing permanent stats file "pg_stat/global.stat"
2016-12-05 16:48:07 CET [1704-4] DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children: 
2016-12-05 16:48:07 CET [1704-5] DEBUG:  CommitTransaction
2016-12-05 16:48:07 CET [1704-6] DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children: 
2016-12-05 16:48:07 CET [1705-4] DEBUG:  received inquiry for database 0
2016-12-05 16:48:07 CET [1705-5] DEBUG:  writing stats file "/var/run/postgresql/9.5-main.pg_stat_tmp/global.stat"
2016-12-05 16:48:07 CET [1705-6] DEBUG:  writing stats file "/var/run/postgresql/9.5-main.pg_stat_tmp/db_0.stat"
2016-12-05 16:48:07 CET [1701-1] DEBUG:  checkpointer updated shared memory configuration values

En caso de una ejecución fallida service postgresql start, no se escriben registros en absoluto /var/log/postgresql. Del mismo modo, no puedo encontrar ningún mensaje relacionado con PostgreSQL en /var/log/messages.

He instalado PostgreSQL a través del repositorio oficial:

# apt-cache policy postgresql-9.5
postgresql-9.5:
  Installed: 9.5.5-1.pgdg80+1
  Candidate: 9.5.5-1.pgdg80+1
  Version table:
 *** 9.5.5-1.pgdg80+1 0
        500 http://apt.postgresql.org/pub/repos/apt/ jessie-pgdg/main amd64 Packages
        100 /var/lib/dpkg/status

Todo esto está en una VM VirtualBox.

Actualización 1

La unidad systemd parece pertenecer al postgresql-commonpaquete:

# find /lib/systemd -iname "*postgres*"
/lib/systemd/system/postgresql.service
/lib/systemd/system/[email protected]
/lib/systemd/system-generators/postgresql-generator

# dpkg -S postgresql.service
postgresql-common: /lib/systemd/system/postgresql.service

# dpkg -S [email protected]
postgresql-common: /lib/systemd/system/[email protected]

# dpkg -S postgresql-generator
postgresql-common: /lib/systemd/system-generators/postgresql-generator

Aquí está su contenido:

/lib/systemd/system/postgresql.service

# systemd service for managing all PostgreSQL clusters on the system. This
# service is actually a systemd target, but we are using a service since
# targets cannot be reloaded.

[Unit]
Description=PostgreSQL RDBMS

[Service]
Type=oneshot
ExecStart=/bin/true
ExecReload=/bin/true
RemainAfterExit=on

[Install]
WantedBy=multi-user.target

/lib/systemd/system/[email protected]

# systemd service template for PostgreSQL clusters. The actual instances will
# be called "postgresql@version-cluster", e.g. "[email protected]". The
# variable %i expands to "version-cluster", %I expands to "version/cluster".
# (%I breaks for cluster names containing dashes.)

[Unit]
Description=PostgreSQL Cluster %i
ConditionPathExists=/etc/postgresql/%I/postgresql.conf
PartOf=postgresql.service
ReloadPropagatedFrom=postgresql.service
Before=postgresql.service

[Service]
Type=forking
# @: use "postgresql@%i" as process name
ExecStart=@/usr/bin/pg_ctlcluster postgresql@%i --skip-systemctl-redirect %i start
ExecStop=/usr/bin/pg_ctlcluster --skip-systemctl-redirect -m fast %i stop
ExecReload=/usr/bin/pg_ctlcluster --skip-systemctl-redirect %i reload
PIDFile=/var/run/postgresql/%i.pid
SyslogIdentifier=postgresql@%i
# prevent OOM killer from choosing the postmaster (individual backends will
# reset the score to 0)
OOMScoreAdjust=-900
# restarting automatically will prevent "pg_ctlcluster ... stop" from working,
# so we disable it here. Also, the postmaster will restart by itself on most
# problems anyway, so it is questionable if one wants to enable external
# automatic restarts.
#Restart=on-failure
# (This should make pg_ctlcluster stop work, but doesn't:)
#RestartPreventExitStatus=SIGINT SIGTERM

[Install]
WantedBy=multi-user.target

/lib/systemd/system-generators/postgresql-generator

#!/bin/sh

# This systemd generator creates dependency symlinks that make all PostgreSQL
# clusters with "auto" in their start.conf file be started/stopped/reloaded
# when postgresql.service is started/stopped/reloaded.

set -eu

gendir="$1"
wantdir="$1/postgresql.service.wants"
pgservice="/lib/systemd/system/[email protected]"

mkdir -p "$wantdir"

for conf in /etc/postgresql/*/*/postgresql.conf; do
    test -e "$conf" || continue
    dir="${conf%/*}"

    # evaluate start.conf
    if [ -e "$dir/start.conf" ]; then
        start=$(sed 's/#.*$//; /^[[:space:]]*$/d; s/^\s*//; s/\s*$//' "$dir/start.conf")
    else
        start=auto
    fi
    [ "$start" = "auto" ] || continue

    verdir="${dir%/*}"
    version="${verdir##*/}"
    cluster="${dir##*/}"
    ln -s "$pgservice" "$wantdir/postgresql@$version-$cluster.service"
done

exit 0

postgresql-commonse instaló desde el repositorio oficial de PostgreSQL como una dependencia del postgresql-9.5paquete:

# apt-cache policy postgresql-common
postgresql-common:
  Installed: 177.pgdg80+1
  Candidate: 177.pgdg80+1
  Version table:
 *** 177.pgdg80+1 0
        500 http://apt.postgresql.org/pub/repos/apt/ jessie-pgdg/main amd64 Packages
        100 /var/lib/dpkg/status
     165+deb8u1 0
        500 http://httpredir.debian.org/debian/ jessie/main amd64 Packages

Actualización 2

Según lo solicitado, aquí está la salida de strace -f service postgresql start Pastebin (debido a su tamaño).

debian postgresql debian-jessie Florian Brucker
fuente
¿ netstat -puntaDespués de iniciarlo manualmente, está postgresescuchando en algún puerto?
sysfiend
@Alex Cuando inicio PostgreSQL manualmente, escucha y acepta conexiones a través de TCP (puerto 5432) y socket de dominio ( /var/run/postgresql/.s.PGSQL.5432). Cuando lo inicio a través de servicenada de eso funciona.
Florian Brucker
Podría straceintentarlo:
Oliver Rahner
strace -f service postgresql start
Oliver Rahner
@OliverRahner: Gracias por la idea, he actualizado mi respuesta con la salida de strace.
Florian Brucker

Respuestas:

6

Hay un par de cosas pasando aquí. Si llama a un servicio systemd con un @, es una señal para iniciar una instancia en lugar del servicio principal. Poner @9.5-maines decirle los parámetros de instancia a usar.

El archivo de servicio postgres que está viendo no es más que un marcador de posición. Hay un directorio en el sistema (normalmente está en algún lugar /run) llamado postgresql.wants.dque el systemd buscará cuando postgresql.servicese inicie.

Todo lo que se encuentre en ese directorio se iniciará junto con él tal como postgresql.servicese dice que lo desea.

Ese directorio se llena a través de un archivo generador de script de shell, ya que todo en /runun tmpfs. Esa es la secuencia de comandos de shell que citó anteriormente.

Si tuviera que arriesgarme a adivinar qué sucede allí a través de la lógica del script de shell, probablemente haya /etc/postgresql/9.5/main/start.confconfigurado el archivo manual.

Esto significa que el generador lo omite y postgresql.wants.dnunca se agrega con ese nombre de instancia.

De acuerdo con la lógica del script, simplemente eliminarlo tiene el efecto correcto de hacerlo automático.

También puede configurarlo autoy hacer un daemon-reloadpara regenerar la configuración necesaria.

Matthew Ife
fuente
Gracias, esto ya ha aclarado mucho! Sin embargo, mi /etc/postgresql/9.5./main/start.confya dice auto. Si ejecuto manualmente /lib/systemd/system-generators/postgresql-generator 9.5-maindesde dentro /run/systemd/generator/postgresql.service.wants, se crea el enlace necesario y todo funciona después de mí systemctl restart postgresl(aunque systemctl status postgresqltodavía lo dice active (exited)). Sin embargo, después de reiniciar, el wantsenlace no se crea automáticamente y systemctl daemon-reloadtampoco lo vuelve a crear. ¿Algunas ideas?
Florian Brucker
Posiblemente podría intentar copiar el generador /etc/systemd/system-generators/y ver si funciona desde esa ruta al reiniciar. Algo podría estar mal con el shellscript en el momento del arranque (¿tal vez un sistema de archivos no está montado?). Tendría que alterar el shellscript para que sea más detallado y almacenar los datos en algún lugar para ver qué se ejecuta desde dentro.
Matthew Ife
systemctl daemon-reloadejecuta el generador, debo haberlo perdido en mi comentario anterior. Sin embargo, no puedo hacer que el generador se ejecute en el momento del arranque, por lo que ahora estoy ejecutando una solución alternativa systemctl daemon-reloady systemctl restart postgresqldespués de arrancar a través de un script de provisión Vagrant. ¡Muchas gracias por tu ayuda!
Florian Brucker
1

A partir del 26 de mayo de 2017, el problema aún existe en Debian 8 (por lo que puedo ver): PostgreSQL no puede iniciarse en el arranque.

La solución por el momento es emitir:

systemctl daemon-reload
systemctl restart postgresql

manualmente en el arranque y todo debería estar bien. Gracias a Florian Brucker por señalar esto arriba.

El error aparentemente está en systemd y, con suerte, debería rectificarse pronto.

Avinash Meetoo
fuente