[OpenSER-Users] when openser starts - mi_fifo reports "pkg_malloc cannot allocate any more memory"
Hello all, we have installed Openser with mysql on a RedHat Enterprise 4 machine. Details are as follows:
Linux Capricadb3 2.6.9-55.ELsmp #1 SMP Fri Apr 20 17:03:35 EDT 2007 i686 i686 i386 GNU/Linux
version: openser 1.3.2-notls (i386/linux) flags: STATS: Off, USE_IPV6, USE_TCP, DISABLE_NAGLE, USE_MCAST, SHM_MEM, SHM_MMAP, PKG_MALLOC, F_MALLOC, FAST_LOCK-ADAPTIVE_WAIT ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535 poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. svnrevision: unknown @(#) $Id: main.c 3590 2008-01-28 17:46:56Z bogdan_iancu $ main.c compiled on 11:26:34 Jul 14 2008 with gcc 3.4.6
When we start openser the child process disappear directly again and the log file shows the following (snippet, this message continues until openser stopped):
Jul 14 11:30:10 Capricadb3 /usr/local/sbin/openser[10344]: INFO:nathelper:rtpp_test: rtp proxy unix:/home/sys/bin/rtpproxy.sock found, support for it enabled Jul 14 11:30:10 Capricadb3 /usr/local/sbin/openser[10344]: DBG:core:init_mod_child: type=CHILD, rank=2, module=mi_fifo Jul 14 11:30:10 Capricadb3 /usr/local/sbin/openser[10344]: ERROR:mi_fifo:mi_writer_init: pkg_malloc cannot allocate any more memory! Jul 14 11:30:10 Capricadb3 /usr/local/sbin/openser[10344]: CRITICAL:mi_fifo:mi_child_init: failed to init the reply writer Jul 14 11:30:10 Capricadb3 /usr/local/sbin/openser[10344]: ERROR:core:init_mod_child: failed to initializing module mi_fifo, rank 2 Jul 14 11:30:10 Capricadb3 /usr/local/sbin/openser[10344]: ERROR:core:main_loop: init_child failed for UDP listener Jul 14 11:30:10 Capricadb3 /usr/local/sbin/openser[10296]: DBG:core:openser_fork: forking new process "UDP receiver" Jul 14 11:30:10 Capricadb3 /usr/local/sbin/openser[10345]: DBG:mysql:db_mysql_new_connection: connection type is capricadb6 via TCP/IP
the end of the log file shows this mem status:
Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: Memory status (pkg): Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: fm_status (0x815f100): Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: heap size= 67108864 Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: used= 36512, used+overhead=57200, free=67051664 Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: max used (+overhead)= 63272 Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: dumping free list: Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: hash = 1 fragments no.: 6, unused: 0 bucket size: 8 - 8 (first 8) Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: hash = 2 fragments no.: 22, unused: 0 bucket size: 16 - 16 (first 16) Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: hash = 3 fragments no.: 3, unused: 0 bucket size: 24 - 24 (first 24) Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: hash = 4 fragments no.: 1, unused: 0 bucket size: 32 - 32 (first 32) Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: hash = 5 fragments no.: 3, unused: 0 bucket size: 40 - 40 (first 40) Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: hash = 7 fragments no.: 1, unused: 0 bucket size: 56 - 56 (first 56) Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: hash = 11 fragments no.: 1, unused: 0 bucket size: 88 - 88 (first 88) Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: hash = 16 fragments no.: 4, unused: 0 bucket size: 128 - 128 (first 128) Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: hash = 35 fragments no.: 1, unused: 0 bucket size: 280 - 280 (first 280) Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: hash = 39 fragments no.: 1, unused: 0 bucket size: 312 - 312 (first 312) Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: hash = 66 fragments no.: 1, unused: 0 bucket size: 528 - 528 (first 528) Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: hash = 67 fragments no.: 1, unused: 0 bucket size: 536 - 536 (first 536) Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: hash = 76 fragments no.: 1, unused: 0 bucket size: 608 - 608 (first 608) Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: hash = 119 fragments no.: 1, unused: 0 bucket size: 952 - 952 (first 952) Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: hash = 513 fragments no.: 1, unused: 0 bucket size: 4104 - 4104 (first 4104) Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: hash = 680 fragments no.: 1, unused: 0 bucket size: 5440 - 5440 (first 0) Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: hash = 2060 fragments no.: 1, unused: 0 bucket size: 33554432 - 67108864 (first 0) Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: TOTAL: 50 free fragments = 8600 free bytes Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: ----------------------------- Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: Memory status (shm): Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: fm_status (0xa7ff2000): Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: heap size= 268435456 Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: used= 16, used+overhead=17672, free=268417784 Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: max used (+overhead)= 1629112 Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: dumping free list: Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: hash = 1 fragments no.: 54, unused: 0 bucket size: 8 - 8 (first 8) Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: hash = 2 fragments no.: 7, unused: 0 bucket size: 16 - 16 (first 16) Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: hash = 3 fragments no.: 6, unused: 0 bucket size: 24 - 24 (first 24) Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: hash = 4 fragments no.: 49, unused: 0 bucket size: 32 - 32 (first 32) Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: hash = 5 fragments no.: 4, unused: 0 bucket size: 40 - 40 (first 40) Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: hash = 8 fragments no.: 2, unused: 0 bucket size: 64 - 64 (first 64) Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: hash = 12 fragments no.: 1, unused: 0 bucket size: 96 - 96 (first 96) Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: hash = 15 fragments no.: 1, unused: 0 bucket size: 120 - 120 (first 120) Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: hash = 64 fragments no.: 1, unused: 0 bucket size: 512 - 512 (first 512) Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: hash = 130 fragments no.: 1, unused: 0 bucket size: 1040 - 1040 (first 1040) Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: hash = 144 fragments no.: 1, unused: 0 bucket size: 1152 - 1152 (first 1152) Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: hash = 257 fragments no.: 1, unused: 0 bucket size: 2056 - 2056 (first 2056) Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: hash = 298 fragments no.: 1, unused: 0 bucket size: 2384 - 2384 (first 2384) Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: hash = 512 fragments no.: 2, unused: 0 bucket size: 4096 - 4096 (first 4096) Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: hash = 1280 fragments no.: 2, unused: 0 bucket size: 10240 - 10240 (first 10240) Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: hash = 2055 fragments no.: 1, unused: 0 bucket size: 1048576 - 2097152 (first 1572864) Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: hash = 2062 fragments no.: 1, unused: 0 bucket size: 134217728 - 268435456 (first 266806344) Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: TOTAL: 135 free fragments = 268417784 free bytes Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: ----------------------------- Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: DBG:core:shm_mem_destroy: Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: DBG:core:shm_mem_destroy: destroying the shared memory lock Jul 14 11:30:15 Capricadb3 /usr/local/sbin/openser[10296]: DBG:core:handle_sigs: terminating due to SIGCHLD (END)
We have configured openser to start 4 childs in the config file.
When we configure 2 childs only it will start. We have tried pretty much everything we can think of, we also used the "DBG_QM_MALLOC" switch in the Makefile.defs but the output in the logfile does not point out anymore helpful infos. We also increased the shared and private memory in the config.h file step by step up to pkg= 64 and shared=256MB without success.
We have the same config running on another machine with pretty much the same spec, just a slower CPU and less memory and there it runs with default settings...
Any help is very appreciated as we are running out of ideas now.
Thanks in advance and best regards,
Christian
On Monday 14 July 2008, Christian Koch wrote:
we have installed Openser with mysql on a RedHat Enterprise 4 machine. Details are as follows: [..] version: openser 1.3.2-notls (i386/linux) [..] When we start openser the child process disappear directly again and the log file shows the following (snippet, this message continues until openser stopped): [..] Jul 14 11:30:10 Capricadb3 /usr/local/sbin/openser[10344]: ERROR:mi_fifo:mi_writer_init: pkg_malloc cannot allocate any more memory! [..] We have configured openser to start 4 childs in the config file.
When we configure 2 childs only it will start. We have tried pretty much everything we can think of, we also used the "DBG_QM_MALLOC" switch in the Makefile.defs but the output in the logfile does not point out anymore helpful infos. We also increased the shared and private memory in the config.h file step by step up to pkg= 64 and shared=256MB without success.
We have the same config running on another machine with pretty much the same spec, just a slower CPU and less memory and there it runs with default settings...
Hi Christian,
strange problem. I assume that you mean 64Mb pkg memory? This is a lot, normally the default/ slightly increased settings should be just fine. Does the error happens all the time in the mi_fifo initialization? Do you use carrierroute with a large route set, or any other module that needs a lot of memory during startup? How much memory the machine have?
Cheers,
Henning
Hi Henning,
see answers below.
Henning Westerholt schrieb:
On Monday 14 July 2008, Christian Koch wrote:
we have installed Openser with mysql on a RedHat Enterprise 4 machine. Details are as follows: [..] version: openser 1.3.2-notls (i386/linux) [..] When we start openser the child process disappear directly again and the log file shows the following (snippet, this message continues until openser stopped): [..] Jul 14 11:30:10 Capricadb3 /usr/local/sbin/openser[10344]: ERROR:mi_fifo:mi_writer_init: pkg_malloc cannot allocate any more memory! [..] We have configured openser to start 4 childs in the config file.
When we configure 2 childs only it will start. We have tried pretty much everything we can think of, we also used the "DBG_QM_MALLOC" switch in the Makefile.defs but the output in the logfile does not point out anymore helpful infos. We also increased the shared and private memory in the config.h file step by step up to pkg= 64 and shared=256MB without success.
We have the same config running on another machine with pretty much the same spec, just a slower CPU and less memory and there it runs with default settings...
I assume that you mean 64Mb pkg memory? This is a lot, normally the default/ slightly increased settings should be just fine.
We started with the default settings and got the same error. So we increased the value up to 64MB, but the error still occurs :-(
Does the error happens all the time in the mi_fifo initialization?
Yes.
Do you use carrierroute with a large route set, or any other module that needs a lot of memory during startup?
We're using the following modules:
loadmodule "mysql.so" loadmodule "sl.so" loadmodule "tm.so" loadmodule "rr.so" loadmodule "maxfwd.so" loadmodule "usrloc.so" loadmodule "registrar.so" loadmodule "auth.so" loadmodule "auth_db.so" loadmodule "uri.so" loadmodule "uri_db.so" loadmodule "nathelper.so" loadmodule "textops.so" loadmodule "mi_fifo.so" loadmodule "gflags.so" loadmodule "xlog.so"
We're not using carrierroute and our database is nearly empty.
How much memory the machine have?
free total used free shared buffers cached Mem: 4150288 4001796 148492 0 190912 3260800 -/+ buffers/cache: 550084 3600204 Swap: 2048276 208 2048068
Do you have any idea if we can set a higher debug level to get more infos about the problem? We already have "debug=6" set in openser.cfg
Any hints are very appreciated. Thanks in advance and best regards, Christian
On Tuesday 15 July 2008, Christian Koch wrote:
I assume that you mean 64Mb pkg memory? This is a lot, normally the default/ slightly increased settings should be just fine.
We started with the default settings and got the same error. So we increased the value up to 64MB, but the error still occurs :-(
Does the error happens all the time in the mi_fifo initialization?
Yes.
Hi Christian,
this is really strange. I know its probably not the case, but do you've any resource limits configured on this machine?
Do you use carrierroute with a large route set, or any other module that needs a lot of memory during startup?
We're using the following modules:
loadmodule "mysql.so" [..] loadmodule "xlog.so"
We're not using carrierroute and our database is nearly empty.
Have you tried to use only a subset of the modules, and see if the error happens again? And if you ommit the mi_fifo module, do you get another error?
Do you have any idea if we can set a higher debug level to get more infos about the problem? We already have "debug=6" set in openser.cfg
You could of course always modify the source, to see how much memory the mi_fifo would like to allocate. But checking the source, i think it should normally allocate 8192 bytes. So the problem is probably located elsewhere.
Cheers,
Henning
Hi Henning,
sorry for the delay. We had some busy days :-(
Have you tried to use only a subset of the modules, and see if the error happens again? And if you ommit the mi_fifo module, do you get another error?
We tried without the mi_fifo and xlog modules, but the error still occured. The log-msg was slightly different:
/usr/local/sbin/openser[21357]: CRITICAL:core:init_io_wait: could not alloc fd hashtable (25008 bytes)
Then we removed mysql and suddenly openser worked fine. So we tried some different scenarios for compiling the mysql module. What now works for us is:
- Linking against the static mysqlclient library (/usr/lib/mysql/libmysqlclient.a) - Additionally using the following libs: -lcrypt -lnsl -lssl -lcrypto (those were suggested by the 'mysql_config' tool - which is not available on our machine, but we got the output from running mysql_config on another machine)
The "LIBS="-section of modules/mysql/Makefile now looks like that:
# libmysqlclient locations on RH/Suse, Solaris /OpenBSD, FreeBSD # (Debian does the right thing and puts it in /usr/lib) LIBS=/usr/lib/mysql/libmysqlclient.a -L$(SYSBASE)/lib -L$(LOCALBASE)/lib -L$(LOCALBASE)/lib/mysql \ -L$(LOCALBASE)/mysql/lib/mysql/ \ -L$(LOCALBASE)/mysql/lib \ -L$(SYSBASE)/lib64/mysql \ -lm -lz -lcrypt -lnsl -lssl -lcrypto
(When trying this on a machine with mysql_config available don't forget to remove the autodetection from the makefile!)
We suspect the mysqlclient installation on that machine to be a little corrupt. Perhaps headers and libs don't belong to the same mysql version. But we have no clue why it doesn't work with the dynamic library but with the static one. Additionally it's interessting that the problem depends on the number of openser childs (as stated in our first mail, with only 2 childs everything works fine - even with the dynamic lib). So perhaps using the static lib is only a workaround for a bug in openser - we simply don't know. Nevertheless, we've got a working openser installation now!!!!!
Thanks for your help and hints, which led us to the solution.
Regards, Christian
On Friday 18 July 2008, Christian Koch wrote:
Have you tried to use only a subset of the modules, and see if the error happens again? And if you ommit the mi_fifo module, do you get another error?
We tried without the mi_fifo and xlog modules, but the error still occured. The log-msg was slightly different:
/usr/local/sbin/openser[21357]: CRITICAL:core:init_io_wait: could not alloc fd hashtable (25008 bytes)
Hi Christian,
ok, now it runs in an other out of memory condition, but otherwise the error is the same.
Then we removed mysql and suddenly openser worked fine. So we tried some different scenarios for compiling the mysql module. What now works for us is:
- Linking against the static mysqlclient library
(/usr/lib/mysql/libmysqlclient.a)
- Additionally using the following libs: -lcrypt -lnsl -lssl -lcrypto
(those were suggested by the 'mysql_config' tool - which is not available on our machine, but we got the output from running mysql_config on another machine)
The "LIBS="-section of modules/mysql/Makefile now looks like that: [..] (When trying this on a machine with mysql_config available don't forget to remove the autodetection from the makefile!)
I've tried it on my machine with disabled autodetection. The module is even in this case linked with additional libraries not included in the Makefile, because of the dependencies stated in libmysqlclient.la.
We suspect the mysqlclient installation on that machine to be a little corrupt. Perhaps headers and libs don't belong to the same mysql version. But we have no clue why it doesn't work with the dynamic library but with the static one. Additionally it's interessting that the problem depends on the number of openser childs (as stated in our first mail, with only 2 childs everything works fine - even with the dynamic lib). So perhaps using the static lib is only a workaround for a bug in openser - we simply don't know. Nevertheless, we've got a working openser installation now!!!!!
This could be the problem, yes. The exact conditions of this error are indeed somewhat strange.. But good that it works for you now. :-)
Cheers,
Henning
-
Christian Koch -
Henning Westerholt