Назад | Перейти на главную страницу

PostgreSQL завершает работу после запуска

Мой сервер PostgreSQL 9.5 на Debian 8 (Jessie) продолжает выходить сразу после запуска через 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.

Обратите внимание active (exited) штат. Сервер не работает, например Я не могу подключиться к нему через TCP или доменный сокет, и я не могу найти никаких связанных процессов.

Однако когда я запустить PostgreSQL вручную оно работает:

# 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)

Журналы в /var/log/postgresql не содержат ничего подозрительного. Вот результат рабочего ручного запуска:

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

В случае неудачного запуска через service postgresql start, никакие журналы не записываются в /var/log/postgresql. Точно так же я не могу найти сообщений, связанных с PostgreSQL, в /var/log/messages.

Я установил PostgreSQL через официальный репозиторий:

# 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

Все это находится на виртуальной машине VirtualBox.

Обновление 1

Модуль systemd, кажется, принадлежит postgresql-common пакет:

# find /lib/systemd -iname "*postgres*"
/lib/systemd/system/postgresql.service
/lib/systemd/system/postgresql@.service
/lib/systemd/system-generators/postgresql-generator

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

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

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

Вот их содержание:

/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/postgresql@.service

# systemd service template for PostgreSQL clusters. The actual instances will
# be called "postgresql@version-cluster", e.g. "postgresql@9.3-main". 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/postgresql@.service"

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-common был установлен из официального репозитория PostgreSQL как зависимость от postgresql-9.5 пакет:

# 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

Обновление 2

По запросу, вот результат strace -f service postgresql start на Pastebin (из-за его размера).

Здесь происходит пара вещей. Если вы вызываете службу systemd с @ в нем это сигнал для запуска экземпляра, а не основной службы. Положив @9.5-main сообщает ему используемые параметры экземпляра.

Файл службы postgres, который вы видите, является не более чем заполнителем. В системе есть каталог (обычно он находится где-то в /run) называется postgresql.wants.d который systemd будет искать, когда postgresql.service запущен.

Все в этом каталоге будет запущено вместе с ним как postgresql.service говорят, что он этого хочет.

Этот каталог заполняется файлом генератора сценария оболочки, как и все в /run это tmpfs. Это сценарий оболочки, который вы цитировали выше.

Если бы мне пришлось рискнуть предположить, что там происходит, с помощью логики сценария оболочки, вы, вероятно, получили файл /etc/postgresql/9.5/main/start.conf установлен в manual.

Это означает, что генератор пропускает его, и postgresql.wants.d никогда не добавляется с этим именем экземпляра.

Согласно логике скрипта, простое его удаление приводит к тому, что он становится автоматическим.

Вы также можете установить его на auto и сделать daemon-reload для регенерации необходимого конфига.

По состоянию на 26 мая 2017 г. проблема все еще существует в Debian 8 (насколько я понимаю): PostgreSQL не запускается при загрузке.

Решение на данный момент заключается в следующем:

systemctl daemon-reload
systemctl restart postgresql

вручную при загрузке, и все должно быть в порядке. Спасибо Флориану Брукеру за указание на это выше.

По всей видимости, ошибка находится в systemd и, надеюсь, скоро будет исправлена.