"service postgresql start" hangs forever over SSH

[jarmo]

I'm trying to provision a FreeBSD 13.1 VM over SSH by running shell commands. Among many other things I'm executing commands like these:

pkg install -y postgresql15-server
service postgresql initdb
service postgresql start

It gets to service postgresql start, prints the following and hangs indefinitely:

2023-04-09 22:49:53.174 EEST [84492] LOG:  ending log output to stde
2023-04-09 22:49:53.174 EEST [84492] HINT:  Future log output will go to log destination "syslog".

I can reproduce it via simple command by not running service postgresql start command via the provisioning script, but executing it after service postgresql initdb manually like this:
ssh freebsd service postgresql start

Again, similar output is printed out and SSH connection will hang indefinitely.

By running this command manually within SSH connection does not cause any problems - it's only problematic when I try to automate postgresql server installation via scripting.

Now, I did google about this problem and found one issue at ansible issue tracker from the year 2016 at https://github.com/ansible/ansible/issues/5923. I'm not using ansible, but the problem description is really similar.

Found one solution from there, which worked for me too:

pkg install -y postgresql15-server
service postgresql initdb
sysrc postgresql_flags="-l /dev/null -w -s -m fast"
service postgresql start

However, it does feel dirty to send log output to /dev/null during provisioning - maybe there's something important which I would like to see? And as I understand then logs will be sent to /dev/null in the future too which is definitely not something I would prefer. Also, it hardcodes postgresql_flags in a way, which might not work in the future.

While writing this post, I've managed to improve above commands a little:

pkg install -y postgresql15-server
service postgresql initdb
service postgresql start >/dev/null

Instead of setting postgresql_flags and affecting all the commands in the future too, I'm just redirecting stdout to /dev/null - yes, I might miss something important/interesting when provisioning, but at least nothing blocks and I expect to receive a non-successful exit code when something goes wrong thus causing provisioning to fail too.

However, postgresql is not the only service I'm installing and starting via provisioning - I don't have any similar problems with anything else so far.

Does anyone know why this problem exists in the first place and what would be the proper solution in this case?

Thank you for all the help.

 

[Alain De Vos]

Could be anything.
-An ansible bug.
-A bad character tab or space in an ansible script.
-The script does not arrive at getting elevated privileges (root).
-A python issue on client or server.
Mostly:
-The script does not expect or does expect something to be written to stdout and/or stderr which does not happen as expected.

Note: "postgresql.conf" has a paramater "log_destination":
-> # Valid values are combinations of stderr, csvlog, syslog, and eventlog

 

[VladiBG]

It's working just fine on clear install of 13.1-RELEASE. Do you have any old database from previous installation of postgresql?

Script started on Mon Apr 10 14:28:49 2023
root@btest:/home/versus # cd /usr/local/etc/rc.d
root@btest:/usr/local/etc/rc.d # ./postgresql rcvar
# postgresql
#
postgresql_enable="NO"
#   (default: "")

root@btest:/usr/local/etc/rc.d # ./postgresql enable
postgresql enabled in /etc/rc.conf
root@btest:/usr/local/etc/rc.d # ./postgresql rcvar
# postgresql
#
postgresql_enable="YES"
#   (default: "")

root@btest:/usr/local/etc/rc.d # ./postgresql initdb
The files belonging to this database system will be owned by user "postgres".
This user must also own the server process.

The database cluster will be initialized with this locale configuration:
  provider:    libc
  LC_COLLATE:  C
  LC_CTYPE:    C.UTF-8
  LC_MESSAGES: C.UTF-8
  LC_MONETARY: C.UTF-8
  LC_NUMERIC:  C.UTF-8
  LC_TIME:     C.UTF-8
The default text search configuration will be set to "english".

Data page checksums are disabled.
creating directory /var/db/postgres/data15 ... ok
creating subdirectories ... ok
selecting dynamic shared memory implementation ... posix
selecting default max_connections ... 100
selecting default shared_buffers ... 128MB
selecting default time zone ... Europe/Sofia
creating configuration files ... ok
running bootstrap script ... ok
performing post-bootstrap initialization ... ok
syncing data to disk ... ok

initdb: warning: enabling "trust" authentication for local connections
initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.

Success. You can now start the database server using:

    /usr/local/bin/pg_ctl -D /var/db/postgres/data15 -l logfile start

root@btest:/usr/local/etc/rc.d # ./postgresql start
2023-04-10 14:29:44.073 EEST [1214] LOG:  ending log output to stderr
2023-04-10 14:29:44.073 EEST [1214] HINT:  Future log output will go to log destination "syslog".
root@btest:/usr/local/etc/rc.d # ./postgresql status
pg_ctl: server is running (PID: 1214)
/usr/local/bin/postgres "-D" "/var/db/postgres/data15"
root@btest:/usr/local/etc/rc.d # exit
exit

Script done on Mon Apr 10 14:29:56 2023

 

[Vull]

Found one solution from there, which worked for me too:

pkg install -y postgresql15-server
service postgresql initdb
sysrc postgresql_flags="-l /dev/null -w -s -m fast"
service postgresql start

However, it does feel dirty to send log output to /dev/null during provisioning - maybe there's something important which I would like to see? And as I understand then logs will be sent to /dev/null in the future too which is definitely not something I would prefer. Also, it hardcodes postgresql_flags in a way, which might not work in the future.

While writing this post, I've managed to improve above commands a little:

pkg install -y postgresql15-server
service postgresql initdb
service postgresql start >/dev/null

Instead of setting postgresql_flags and affecting all the commands in the future too, I'm just redirecting stdout to /dev/null - yes, I might miss something important/interesting when provisioning, but at least nothing blocks and I expect to receive a non-successful exit code when something goes wrong thus causing provisioning to fail too.

However, postgresql is not the only service I'm installing and starting via provisioning - I don't have any similar problems with anything else so far.

Does anyone know why this problem exists in the first place and what would be the proper solution in this case?

Thank you for all the help.

I haven't tested this, but why not try something like:

pkg install -y postgresql15-server
service postgresql initdb
service postgresql start > /home/jarmo/my-postgresql-startup.log

That way, you would preserve whatever important messages postgresql sends, which you could review later, at your leisure (substituting your own choice of directory and location filename in place of the > /home/jarmo/my-postgresql-startup.log designator I used in my example).

As for why the "problem exists in the first place," I think I would go with user "swills" who said (and I quote): "It's due [to] the python subprocess popen communicate function waiting on the process to exit or close stdout (I think)," in the reference you quoted above, which was: https://github.com/ansible/issues/5923

 

[jarmo]

Thank you for all the answers so far.

It seems to me that pointing to ansible issue I've made things more confusing as they should be. I did it only because symptoms are similar to the ones I'm experiencing, but I cannot guarantee that the problem itself is something different.
So let me re-iterate:
1) I'm not using Ansible at all;
2) There should be no Python in play due to the previous point;
3) It is a clean installation of FreeBSD 13.1 inside VM with no previous existing database;
4) I can reproduce it 100% of time;

Here are the exact steps to reproduce:
1) Install FreeBSD 13.1 to VM;
2) Enable login over SSH using root for simplicity;
3) SSH into it from host machine:

ssh root@freebsd

4) Inside VM, install postgresql-server

pkg install -y postgresql15-server
service postgresql initdb

5) Disconnect from VM SSH
6) Execute the following command on host machine (so outside of VM):

ssh root@freebsd /usr/local/etc/rc.d/postgresql start

7) The following output will be shown and SSH will not disconnect/keeps blocking (thus breaking any scripts being ran from host machine):

2023-04-09 23:01:18.829 EEST [18069] LOG: ending log output to stderr
2023-04-09 23:01:18.829 EEST [18069] HINT: Future log output will go to log destination "syslog".

Everything works as expected with ssh root@freebsd /usr/local/etc/rc.d/postgresql start command or when psql server has been already started and an error message is shown like this:

$ ssh root@freebsd /usr/local/etc/rc.d/postgresql start
pg_ctl: another server might be running; trying to start server anyway
2023-04-09 23:09:45.281 EEST [25536] FATAL: lock file "postmaster.pid" already exists
2023-04-09 23:09:45.281 EEST [25536] HINT: Is another postmaster (PID 18069) running in data directory "/var/db/postgres/data15"?
pg_ctl: could not start server
Examine the log output.
$ # back at host machine as expected

So no Ansible or Python in play, just plain old boring SSH and pg_ctl.

Can anyone else reproduce this issue or is it just me? So far reading the replies I have a suspicion that all the commands were executed inside of VM/server and not from host using SSH. The problem happens only when command is being executed like shown above.

 

[jarmo]

Has anyone tried the steps provided above to reproduce this issue besides me? Would be good to know that it's not just me experiencing this problem.