[OpenSER-Users] openser 1.3 sometimes fails to start

Fri Nov 30 15:35:38 CET 2007

Hi Bogdan,

I managed to reproduce this issue using the default config file
(latest svn) with the following updates:
  - set the number of children to 1
children=1
  - add the mi_datagram module to the config
loadmodule "mi_datagram.so"
# -- mi_datagram params
modparam("mi_datagram", "socket_name", "/tmp/openser_sock")
modparam("mi_datagram", "unix_socket_mode", 0600)
modparam("mi_datagram", "unix_socket_user", "root")
modparam("mi_datagram", "unix_socket_group", "root")

It takes a few start/stop cycles until the issue is reproduced.

Regards,
Ovidiu Sas

On Nov 30, 2007 9:12 AM, Bogdan-Andrei Iancu <bogdan at voice-system.ro> wrote:
> Hi,
>
> are you using the latest 1.3 - there was a similar issue fixed couple of
> weeks ago ? if so, what module are you loading?
>
> regards,
> bogdan
>
>
> Ovidiu Sas wrote:
> > I experienced similar issues.  I think it is related to the TCP process.
> > I I disable TCP the error doesn't show up.
> >
> > Nov 28 17:42:06 localhost oser[26823]: DBG:core:init_mod_child:
> > type=PROC_TCP_MAIN, rank=-4, module=tm
> > Nov 28 17:42:06 localhost oser[26823]: DBG:tm:child_init_callid:
> > callid: '794ff7ed-26823 at 127.0.0.1'
> > Nov 28 17:42:06 localhost oser[26823]: DBG:core:init_mod_child:
> > type=PROC_TCP_MAIN, rank=-4, module=usrloc
> > Nov 28 17:42:06 localhost oser[26823]: DBG:core:init_mod_child:
> > type=PROC_TCP_MAIN, rank=-4, module=registrar
> > Nov 28 17:42:06 localhost oser[26823]: DBG:core:init_mod_child:
> > type=PROC_TCP_MAIN, rank=-4, module=xlog
> > Nov 28 17:42:06 localhost oser[26823]: DBG:xlog:child_init: init_child
> > [-4]  pid [26823]
> > Nov 28 17:42:06 localhost oser[26823]: DBG:core:init_mod_child:
> > type=PROC_TCP_MAIN, rank=-4, module=mi_fifo
> > Nov 28 17:42:06 localhost oser[26823]: DBG:core:init_mod_child:
> > type=PROC_TCP_MAIN, rank=-4, module=mi_datagram
> > Nov 28 17:42:06 localhost oser[26823]: DBG:core:io_watch_add:
> > io_watch_add(0x8136940, 7, 1, 0x8160420), fd_no=0
> > Nov 28 17:42:06 localhost oser[26823]: DBG:core:io_watch_add:
> > io_watch_add(0x8136940, 8, 1, 0x81604b0), fd_no=1
> > Nov 28 17:42:06 localhost oser[26823]: DBG:core:io_watch_add:
> > io_watch_add(0x8136940, 9, 4, 0x403e8ebc), fd_no=2
> > Nov 28 17:42:06 localhost oser[26823]: DBG:core:io_watch_add:
> > io_watch_add(0x8136940, 10, 4, 0x403e8f48), fd_no=3
> > Nov 28 17:42:06 localhost oser[26823]: DBG:core:io_watch_add:
> > io_watch_add(0x8136940, 11, 4, 0x403e8fd4), fd_no=4
> > Nov 28 17:42:06 localhost oser[26823]: DBG:core:io_watch_add:
> > io_watch_add(0x8136940, 14, 4, 0x403e9060), fd_no=5
> > Nov 28 17:42:06 localhost oser[26823]: DBG:core:io_watch_add:
> > io_watch_add(0x8136940, 12, 4, 0x403e90ec), fd_no=6
> > Nov 28 17:42:06 localhost oser[26823]: DBG:core:io_watch_add:
> > io_watch_add(0x8136940, 16, 4, 0x403e9178), fd_no=7
> > Nov 28 17:42:06 localhost oser[26823]: DBG:core:io_watch_add:
> > io_watch_add(0x8136940, 15, 4, 0x403e9204), fd_no=8
> > Nov 28 17:42:06 localhost oser[26823]: ERROR:core:io_watch_add:
> > epoll_ctl failed: Invalid argument [22]
> > Nov 28 17:42:06 localhost oser[26823]: CRITICAL:core:tcp_main_loop:
> > failed to add process 7 (TCP main) unix socket to the fd list
> > Nov 28 17:42:06 localhost oser[26823]: CRITICAL:core:tcp_main_loop: exiting...
> > Nov 28 17:42:06 localhost oser[26813]: INFO:core:handle_sigs: child
> > process 26823 exited normally, status=255
> > Nov 28 17:42:06 localhost oser[26813]: INFO:core:handle_sigs:
> > terminating due to SIGCHLD
> > Nov 28 17:42:06 localhost oser[26817]: INFO:core:sig_usr: signal 15 received
> > Nov 28 17:42:06 localhost oser[26818]: INFO:core:sig_usr: signal 15 received
> > Nov 28 17:42:06 localhost oser[26819]: INFO:core:sig_usr: signal 15 received
> > Nov 28 17:42:06 localhost oser[26820]: INFO:core:sig_usr: signal 15 received
> >
> >
> >
> > Regards,
> > Ovidiu Sas
> >
> > On Nov 29, 2007 6:06 PM, Robert Dyck <rob.dyck at telus.net> wrote:
> >
> >> I am testing openser 1.3.0-pre1-notls svnversion 2:3201. I believe it is
> >> failing while starting the child processes for the modules. If it starts
> >> successfully it seems to perform normally.
> >>
> >> I believe the following excerpt from the console might hold the clue.
> >> Thanks Rob
> >>
> >> Nov 29 14:40:30 [10492] DBG:xlog:child_init: init_child [0]  pid [10492]
> >> Nov 29 14:40:30 [10492] DBG:core:init_mod_child: type=PROC_MAIN, rank=0,
> >> module=avpops
> >> Nov 29 14:40:30 [10498] DBG:core:io_watch_add: io_watch_add(0x8160900, 6, 4,
> >> 0xb5f824a4), fd_no=0
> >> Nov 29 14:40:30 [10498] DBG:core:io_watch_add: io_watch_add(0x8160900, 7, 4,
> >> 0xb5f82530), fd_no=1
> >> Nov 29 14:40:30 [10498] DBG:core:io_watch_add: io_watch_add(0x8160900, 8, 4,
> >> 0xb5f825bc), fd_no=2
> >> Nov 29 14:40:30 [10498] DBG:core:io_watch_add: io_watch_add(0x8160900, 9, 4,
> >> 0xb5f82648), fd_no=3
> >> Nov 29 14:40:30 [10498] DBG:core:io_watch_add: io_watch_add(0x8160900, 12, 4,
> >> 0xb5f826d4), fd_no=4
> >> Nov 29 14:40:30 [10498] DBG:core:io_watch_add: io_watch_add(0x8160900, 11, 4,
> >> 0xb5f82760), fd_no=5
> >> Nov 29 14:40:30 [10498] ERROR:core:io_watch_add: epoll_ctl failed: Invalid
> >> argument [22]
> >> Nov 29 14:40:30 [10498] CRITICAL:core:tcp_main_loop: failed to add process 6
> >> (TCP main) unix socket to the fd list
> >> Nov 29 14:40:30 [10498] CRITICAL:core:tcp_main_loop: exiting...Nov 29 14:40:30
> >> [10497] INFO:nathelper:rtpp_test: rtp proxy <unix:/var/run/rt
> >> pproxy.sock> found, support for it enabled
> >> Nov 29 14:40:30 [10497] DBG:core:init_mod_child: type=CHILD, rank=3,
> >> module=xlog
> >> Nov 29 14:40:30 [10497] DBG:xlog:child_init: init_child [3]  pid [10497]
> >> Nov 29 14:40:30 [10497] DBG:core:init_mod_child: type=CHILD, rank=3,
> >> module=avpops
> >> Nov 29 14:40:30 [10497] DBG:core:io_watch_add: io_watch_add(0x8160a60, 11, 1,
> >> (nil)), fd_no=0
> >> Nov 29 14:40:30 [10492] INFO:core:handle_sigs: child process 10498 exited
> >> normally, status=255
> >> Nov 29 14:40:30 [10492] INFO:core:handle_sigs: terminating due to SIGCHLD
> >> Nov 29 14:40:30 [10493] INFO:core:sig_usr: signal 15 received
> >> Memory status (pkg):
> >> qm_status (0x8181760):
> >>  heap size= 1048576
> >>  used= 44448, used+overhead=71504, free=977072
> >>  max used (+overhead)= 71504
> >> dumping all alloc'ed. fragments:
> >>       0. N  address=0x8186908 frag=0x8186900 size=32 used=1
> >>       1. N  address=0x8186938 frag=0x8186930 size=16 used=1
> >>       2. N  address=0x8186958 frag=0x8186950 size=32 used=1
> >>       3. N  address=0x8186988 frag=0x8186980 size=32 used=1
> >>       4. N  address=0x81869b8 frag=0x81869b0 size=16 used=1
> >>       5. N  address=0x81869d8 frag=0x81869d0 size=16 used=1
> >>       6. N  address=0x81869f8 frag=0x81869f0 size=32 used=1
> >>       7. N  address=0x8186a28 frag=0x8186a20 size=32 used=1
> >>       8. N  address=0x8186a58 frag=0x8186a50 size=64 used=1
> >>       9. N  address=0x8186aa8 frag=0x8186aa0 size=64 used=1
> >>      10. N  address=0x8186af8 frag=0x8186af0 size=64 used=1
> >>
> >> _______________________________________________
> >> Users mailing list
> >> Users at lists.openser.org
> >> http://lists.openser.org/cgi-bin/mailman/listinfo/users
> >>
> >>
> >
> > _______________________________________________
> > Users mailing list
> > Users at lists.openser.org
> > http://lists.openser.org/cgi-bin/mailman/listinfo/users
> >
> >
>
>