Applications started multiple times



  • I'm running 2.0-RC1-IPv6 (i386)
    built on Fri Aug 26 18:54:18 EDT 2011

    I've noticed siproxd seems to get started multiple times:

    clog /var/log/system.log | grep siproxd

    Sep  1 08:26:12 pfsense siproxd[5662]: siproxd.c:247 INFO:siproxd-0.8.0-5472 i386-portbld-freebsd8.1 starting up
    Sep  1 08:26:12 pfsense siproxd[6276]: siproxd.c:295 INFO:daemonized, pid=6276
    Sep  1 08:26:12 pfsense siproxd[6276]: plugins.c:112 INFO:Plugin 'plugin_logcall' [Logs calls to syslog] loaded with success, exemask=0x40
    Sep  1 08:26:12 pfsense siproxd[6276]: sock.c:131 INFO:bound to port 5060
    Sep  1 08:26:12 pfsense siproxd[6276]: siproxd.c:349 INFO:siproxd-0.8.0-5472 i386-portbld-freebsd8.1 started
    Sep  1 08:26:17 pfsense siproxd[35862]: siproxd.c:247 INFO:siproxd-0.8.0-5472 i386-portbld-freebsd8.1 starting up
    Sep  1 08:26:17 pfsense siproxd[36560]: siproxd.c:295 INFO:daemonized, pid=36560
    Sep  1 08:26:17 pfsense siproxd[36560]: plugins.c:112 INFO:Plugin 'plugin_logcall' [Logs calls to syslog] loaded with success, exemask=0x40
    Sep  1 08:26:18 pfsense siproxd[36560]: sock.c:543 ERROR:bind failed: Address already in use
    Sep  1 08:26:18 pfsense siproxd[36560]: siproxd.c:337 ERROR:unable to bind to SIP listening socket - aborting

    ps ax | grep siproxd

    6276  ??  S      0:00.20 /usr/local/sbin/siproxd -c /usr/local/etc/siproxd.conf
    4584  0  R+    0:00.01 grep siproxd

    and so does pfflowd:

    clog /var/log/system.log | grep pfflowd

    Sep  1 08:26:18 pfsense pfflowd[38723]: pfflowd listening on pfsync0
    Sep  1 08:26:18 pfsense pfflowd[38723]: pfflowd listening on pfsync0
    Sep  1 08:26:18 pfsense pfflowd[38914]: pfflowd listening on pfsync0
    Sep  1 08:26:18 pfsense pfflowd[38914]: pfflowd listening on pfsync0

    ps ax | grep pfflowd

    38723  ??  Ss    0:00.56 /usr/local/sbin/pfflowd -n sme.example.org:5678 -S any -v 5
    38914  ??  Ss    0:00.59 /usr/local/sbin/pfflowd -n sme.example.org:5678 -S any -v 5
    27488  0  R+    0:00.01 grep pfflowd

    In the case of siproxd it seems benign (apart from delaying the startup a little), but in the case of pfflowd it seems to result in duplicate flow records at the collector.

    This seems to have been happening for a while, at least since the Jun 20 snapshot build which I have just replaced.



  • Due to another problem I went back to my Jun 21 snapshot build, upgraded to Aug 26 snapshot build then gitsync'd to get IPv6 support. On reboot after the gitsync, pfflowd appears to get started multiple times but only one copy is left running:

    ps ax | grep pfflowd

    52323  ??  SNs    0:00.24 /usr/local/sbin/pfflowd -n sme.example.org:5678 -S any -v 5
    39759  0  R+    0:00.01 grep pfflowd

    clog /var/log/system.log | grep pfflowd

    Sep  2 11:30:36 pfsense pfflowd[2924]: pfflowd listening on pfsync0
    Sep  2 11:30:36 pfsense pfflowd[2924]: pfflowd listening on pfsync0
    Sep  2 11:30:38 pfsense pfflowd[5216]: pfflowd listening on pfsync0
    Sep  2 11:30:38 pfsense pfflowd[5216]: pfflowd listening on pfsync0
    Sep  2 11:30:41 pfsense pfflowd[5216]: pfflowd exiting on signal 15
    Sep  2 11:30:41 pfsense pfflowd[2924]: pfflowd exiting on signal 15
    Sep  2 11:30:45 pfsense pfflowd[52323]: pfflowd listening on pfsync0
    Sep  2 11:30:45 pfsense pfflowd[52323]: pfflowd listening on pfsync0

    siproxd is still started multiple times with one copy left running:

    clog /var/log/system.log | grep siproxd

    Sep  2 11:30:28 pfsense siproxd[58103]: siproxd.c:247 INFO:siproxd-0.8.0-5472 i386-portbld-freebsd8.1 starting up
    Sep  2 11:30:28 pfsense siproxd[58359]: siproxd.c:295 INFO:daemonized, pid=58359
    Sep  2 11:30:28 pfsense siproxd[58359]: plugins.c:112 INFO:Plugin 'plugin_logcall' [Logs calls to syslog] loaded with success, exemask=0x40
    Sep  2 11:30:28 pfsense siproxd[58359]: sock.c:131 INFO:bound to port 5060
    Sep  2 11:30:28 pfsense siproxd[58359]: siproxd.c:349 INFO:siproxd-0.8.0-5472 i386-portbld-freebsd8.1 started
    Sep  2 11:30:34 pfsense siproxd[62885]: siproxd.c:247 INFO:siproxd-0.8.0-5472 i386-portbld-freebsd8.1 starting up
    Sep  2 11:30:34 pfsense siproxd[63269]: siproxd.c:295 INFO:daemonized, pid=63269
    Sep  2 11:30:34 pfsense siproxd[63269]: plugins.c:112 INFO:Plugin 'plugin_logcall' [Logs calls to syslog] loaded with success, exemask=0x40
    Sep  2 11:30:34 pfsense siproxd[63269]: sock.c:131 INFO:bound to port 5060
    Sep  2 11:30:34 pfsense siproxd[63269]: siproxd.c:349 INFO:siproxd-0.8.0-5472 i386-portbld-freebsd8.1 started
    Sep  2 11:30:36 pfsense siproxd[2489]: siproxd.c:247 INFO:siproxd-0.8.0-5472 i386-portbld-freebsd8.1 starting up
    Sep  2 11:30:36 pfsense siproxd[2808]: siproxd.c:295 INFO:daemonized, pid=2808
    Sep  2 11:30:36 pfsense siproxd[2808]: plugins.c:112 INFO:Plugin 'plugin_logcall' [Logs calls to syslog] loaded with success, exemask=0x40
    Sep  2 11:30:36 pfsense siproxd[2808]: sock.c:543 ERROR:bind failed: Address already in use
    Sep  2 11:30:36 pfsense siproxd[2808]: siproxd.c:337 ERROR:unable to bind to SIP listening socket - aborting
    Sep  2 11:30:41 pfsense siproxd[25686]: siproxd.c:247 INFO:siproxd-0.8.0-5472 i386-portbld-freebsd8.1 starting up
    Sep  2 11:30:41 pfsense siproxd[26409]: siproxd.c:295 INFO:daemonized, pid=26409
    Sep  2 11:30:41 pfsense siproxd[26409]: plugins.c:112 INFO:Plugin 'plugin_logcall' [Logs calls to syslog] loaded with success, exemask=0x40
    Sep  2 11:30:42 pfsense siproxd[26409]: sock.c:131 INFO:bound to port 5060
    Sep  2 11:30:42 pfsense siproxd[26409]: siproxd.c:349 INFO:siproxd-0.8.0-5472 i386-portbld-freebsd8.1 started

    ps ax | grep siprox

    26409  ??  SN    0:00.25 /usr/local/sbin/siproxd -c /usr/local/etc/siproxd.conf
    50356  0  S+    0:00.01 grep siprox


Log in to reply