Re: [prosody-users] Debug messages get appended to pidfile

[Matthew Wild]

Hi Alex,

On 24 September 2012 19:19, alexe <al...@thirdlane.com> wrote:
> I am new to prosody. Installed the latest prosody on CentOS 6.3 from EPEL
> rpm

Welcome!

> While starting prosody either through /etc/init.d/prosody or directly via
> prosodyctl i was getting a message saymg something that the server is still
> not available/not ready/still teying (sorry,I don't have access to the
> system at the moment) .I ran it as root but my understanding is that it
> switches to prosody user.
>
> Looking at pid file shows that some of the debug messages get written to the
> file after the actual pid, so the "not ready" most likely was due to the
> prosodyctl not being able to get the pid from the pidfile. What I run is
> almost out of the box - I did very basic modifications to config file -
> enabled a virtual host and specified logging for debug (on global level) to
> /var/log/prosody/prosody.log. I tried specifying different locations for
> pidfile - result is the same. Also - log file i specify does contain logging
> information - so apparently it is written both there and to the pid file.
> This also happens if i don't specify debug logging target - so it appears
> that debugging messages get written to pid regardless of where debug is
> specified in logging section of config.

I think you correctly diagnosed the issue. Debug messages definitely
shouldn't be written to the pidfile. Can you paste your logging
config? (look for the 'log' option in your config file).

Regards,
Matthew

[alexe]

Hi Matthew,

Thank you for a quick response.

Here is a relevant part of the config file:

--pidfile = "/var/run/prosody/prosody.pid";

pidfile = "/tmp/prosody.pid";

-- Logging configuration

-- For advanced logging see http://prosody.im/doc/logging

log = {

        -- info = "prosody.log"; -- Change 'info' to 'debug' for verbose logging

        debug = "/var/log/prosody/prosody.log"; -- Change 'info' to 'debug' for verbose logging

        -- error = "prosody.err";

        "*syslog"; -- Uncomment this for logging to syslog

         "*console"; -- Log to the console, useful for debugging with daemonize=false

}

Here is what I get in the shell:

[root@thirdlane accounts]# prosodyctl restart

Stopped

general             info Hello and welcome to Prosody version 0.8.2

connlisteners       debug Registered connection listener httpclient

general             info Prosody is using the select backend for connection handling

hostmanager         debug Activated host: example.com

auth_internal_plain  debug initializing default authentication provider for host 'example.com'

usermanager          debug host 'example.com' now set to use user provider 'internal_plain'

connlisteners        debug Registered connection listener console

socket               debug server.lua: new server listener on '127.0.0.1:5582'

Still waiting...

Prosody is still not running. Please give it some time or check your log files for errors.

And here is what is in the pidfile after this:

32653connlisteners        debug Registered connection listener xmppclient

socket               debug      server.lua: new server listener on '*:5222'

connlisteners        debug      Registered connection listener xmppserver

socket               debug      server.lua: new server listener on '*:5269'

connlisteners        debug      Registered connection listener xmppcomponent

socket               debug      server.lua: new server listener on '127.0.0.1:5347'

If you'd like I could look in the source and add some more debugging to get more diagnostics.

 
Thanks,

Alex

On Monday, September 24, 2012 11:19:48 AM UTC-7, alexe wrote:

I am new to prosody. Installed the latest prosody on CentOS 6.3 from EPEL rpm  

While starting prosody either through /etc/init.d/prosody or directly via prosodyctl i was getting a message saymg something that the server is still not available/not ready/still teying (sorry,I don't have access to the system at the moment) .I ran it as root but my understanding is that it switches to prosody user.

Looking at pid file shows that some of the debug messages get written to the file after the actual pid, so the "not ready" most likely was due to the prosodyctl not being able to get the pid from the pidfile.  What I run is almost out of the box - I did very basic modifications to config file - enabled a virtual host and specified logging for debug (on global level) to /var/log/prosody/prosody.log. I tried specifying different locations for pidfile - result is the same. Also - log file i specify does contain logging information - so apparently it is written both there and to the pid file. This also happens if i don't specify debug logging target - so it appears that debugging messages get written to pid regardless of where debug is specified in logging section of config.

Other than that server works  - except for prosodyctl which understandably complains about invalid pid

With minor pointers I could look at the source code but I wonder if anyone ran into this.

Thanks,

Alex

[Matthew Wild]

On 25 September 2012 00:20, alexe <al...@thirdlane.com> wrote:
> Hi Matthew,
>
> Thank you for a quick response.
>
> Here is a relevant part of the config file:
>
> --pidfile = "/var/run/prosody/prosody.pid";
> pidfile = "/tmp/prosody.pid";
>
> -- Logging configuration
> -- For advanced logging see http://prosody.im/doc/logging
> log = {
> -- info = "prosody.log"; -- Change 'info' to 'debug' for verbose
> logging
> debug = "/var/log/prosody/prosody.log"; -- Change 'info' to 'debug'
> for verbose logging
> -- error = "prosody.err";
> "*syslog"; -- Uncomment this for logging to syslog
> "*console"; -- Log to the console, useful for debugging with
> daemonize=false
> }

This is the problematic part. Since Prosody is daemonizing, you need
to remove (or comment) the "*console" line.

The next version will contain a check to warn about this and prevent
it from happening.

Regards,
Matthew

[alexe]

Matthew, thank you very much!

In retrospect I should have realized that logging to console may have something to do with this - but that is in retrospect :).

We clearly need expertise if we were to use prosody. Can I contact you to talk about possible help/consulting? 

Best regards,

[Matthew Wild]

On 25 September 2012 02:51, alexe <al...@thirdlane.com> wrote:
> Matthew, thank you very much!

Glad that it solved the problem!

> In retrospect I should have realized that logging to console may have
> something to do with this - but that is in retrospect :).

It actually isn't so obvious, and I bumped into it myself once. For
anyone curious, this is what's actually happening:

Prosody starts up, attached to the console via stdin, stdout and
stderr. As part of our daemonization process we close these (standard
practice).

Every open file is identified by a file descriptor (fd), which is a
number. stdin, stdout and stderr have fd numbers 0, 1, and 2
respectively. Unfortunately after we close them, those fds become
unused. Next time we open a file, the system re-uses those fds. This
is fine if nothing we do attempts to write to stdout/stderr (or read
from stdin) - but in the case of the console logger, it does.

> We clearly need expertise if we were to use prosody. Can I contact you to
> talk about possible help/consulting?

Sure, feel free to email me at mat...@prosody.im.

Regards,
Matthew