Server not starting when using devpi-ldap and "--start"

[StephanErb]

I have successfully validated my config using the command devpi-ldap. I can also start the server either without the --ldap-config flag or without the --startflag. However, when using both, the devpi server never comes up. There is no log output whatsoever.

$ devpi-server --serverdir data  --ldap-config ldap.yml --start
2014-10-27 15:37:22,418 INFO  NOCTX DB: Creating schema
2014-10-27 15:37:22,583 INFO  [Wtx-1] setting password for user u'root'
2014-10-27 15:37:22,584 INFO  [Wtx-1] created user u'root' with email None
2014-10-27 15:37:22,584 INFO  [Wtx-1] created root user
2014-10-27 15:37:22,584 INFO  [Wtx-1] created root/pypi index
2014-10-27 15:37:22,656 INFO  [Wtx-1] fswriter0: committed: keys: u'.config',u'root/.config'
starting background devpi-server at http://localhost:3141
/tmp/devpildap-dir/data/.xproc/devpi-server$ /tmp/devpildap/bin/devpi-server --serverdir data --ldap-config ldap.yml
process u'devpi-server' started pid=21478
Traceback (most recent call last):
  File "/tmp/devpildap/bin/devpi-server", line 9, in <module>
    load_entry_point('devpi-server==2.1.2', 'console_scripts', 'devpi-server')()
  File "/tmp/devpildap/local/lib/python2.7/site-packages/devpi_server/main.py", line 57, in main
    return _main(argv, hook=hook)
  File "/tmp/devpildap/local/lib/python2.7/site-packages/devpi_server/main.py", line 93, in _main
    return bgserver.start(args)
  File "/tmp/devpildap/local/lib/python2.7/site-packages/devpi_server/bgserver.py", line 69, in start
    self.xproc.ensure("devpi-server", prepare_devpiserver)
  File "/tmp/devpildap/local/lib/python2.7/site-packages/devpi_server/vendor/xprocess.py", line 163, in ensure
    raise RuntimeError("Could not start process %s" % name)
RuntimeError: Could not start process devpi-server

Pip freeze:

Chameleon==2.16
PasteDeploy==1.5.2
PyYAML==3.11
Pygments==1.6
WebOb==1.4
Whoosh==2.6.0
argparse==1.2.1
beautifulsoup4==4.3.2
devpi-common==2.0.3
devpi-ldap==1.0.1
devpi-server==2.1.2
devpi-web==2.2.1
docutils==0.12
execnet==1.2.0
itsdangerous==0.24
py==1.4.26
pyasn1==0.1.7
pyramid==1.5.1
pyramid-chameleon==0.3
python3-ldap==0.9.5.4
repoze.lru==0.6
requests==2.4.3
translationstring==1.1
venusian==1.0
waitress==0.8.9
wsgiref==0.1.2
zope.deprecation==4.1.1
zope.interface==4.1.1

All happens in a fresh virtualenv and with a fresh data dir.

Any idea?

[fschulze]

It looks like the library used to let devpi-server daemonize itself changes the current working directory. In the log which is stored in [server directory]/.xproc/devpi-server/xprocess.log I saw that devpi-ldap can't find the config. You have to use an absolute path when using --start.

[StephanErb]

Ah, good catch.

[fschulze]

So, does it work now? Can I close the ticket? Or do you have suggestions to improve the docs?

[StephanErb]

Yes, it works with fully qualified paths.

However, I guess the server should fail when it cannot find the specified configuration.

[fschulze]

@hpk42 do you have an idea why it doesn't? It seems to time out instead. I couldn't find out why yet.

[hpk42]

devpi-server --start will start a subprocess and wait until the sub process is reachable for 60 seconds or so. So when the process crashes it will still wait this time. It's probably a good idea to refine this startup procedure such that we a) more immediadely fail instead of timing out b) show the content of the log or at least the location of it.

On Mon, Oct 27, 2014 at 10:19 PM, Florian Schulze [email protected] wrote:

@hpk42 https://github.com/hpk42 do you have an idea why it doesn't? It seems to time out instead. I couldn't find out why yet.

— Reply to this email directly or view it on GitHub https://github.com/devpi/devpi-ldap/issues/7#issuecomment-60671292.

[msabramo]

I wonder if https://bitbucket.org/hpk42/devpi/pull-request/187/log-location-of-nodeinfo-file-on-startup/diff helps with the logging issue?

That causes logging to get turned on earlier, because currently logging is not active until after options are parsed and there are things that can go wrong before logging is active.