Informix 12.10 Segfault on CentOS7
Posted in 2016
Florian saw random crashes of IDS 12.10.FC5W1 on CentOS 7, with assertion failures "semop: errno = 43" (EIDRM, identifier removed) in mt.c. Kernel semaphore/shared-memory parameter tuning didn't help, and only one instance was running (ruling out the onclean APAR). The cause turned out to be systemd's RemoveIPC=yes, which deletes IPC objects of non-system users (informix had uid 1000) when their last login session ends. Setting RemoveIPC=no in logind.conf fixed it; alternatives include giving informix a system uid and starting the server via a systemd unit. The thread also notes onstat -b and onmode -c (checkpoint) to flush data, since unlogged databases lose recent data on crash.
Auto-generated by DrWatson from the posts below — may be imperfect; read the full thread.
Topics: Installation, Setup & Upgrades, Error Codes & Troubleshooting, Cloud, Docker & Containers, Versions, Editions & End-of-Life
I just installed IDS 12.10 on CentOS7 and get random segfaults. During the time it crashes I am not doing anything aside from running just a "select * from table" for test purposes and maybe a "load from insert into". That said I cannot exactly correlate any of the queries to the segfault. Selinux is set to permissive. I've added what I could gather from log files, but I am somewhat out of ides. Any hints on how to debug this? Thanks, Florian Instance log: ----- 15:30:44 IBM Informix Dynamic Server Version 12.10.FC5W1WE 15:30:44 Who: Thread(0, idle, 0, 9) File: mt.c Line: 1554 15:30:44 stack trace for pid 15723 written to /opt/informix/tmp/af.90394 15:30:44 See Also: /opt/informix/tmp/af.90394 15:30:44 Thread ID 0 will NOT be suspended because it is deemed too critical to the server. 15:30:44 See Also: /opt/informix/tmp/af.90394, shmem.90394.0 15:30:45 Starting crash time check of: 15:30:45 1. memory block headers 15:30:45 2. stacks 15:30:45 Crash time checking found no problems 15:30:45 mt.c, line 1554, thread 0, proc id 15723, semop: errno = 43 ------ af.90394: ------ 15:30:44 15:30:44 IBM Informix Dynamic Server Version 12.10.FC5W1WE Software Serial Number AAA#B000000 15:30:44 Assert Failed: semop: errno = 43 15:30:44 Who: Thread(0, idle, 0, 9) File: mt.c Line: 1554 15:30:44 SHM Globals and Master Pool/Master Block Adresses: 15:30:44 shmcb = 0x000000004401a418 15:30:44 rhead = 0x0000000044086800 15:30:44 pool list = 0x000000004401a4f0 15:30:44 block pool list = 0x00000000440810f8 15:30:44 TRANSP = 0x0000000045194800 15:30:44 PARTP = 0x0000000000000000 15:30:44 PARTNP = 0x0000000000000000 15:30:44 OPENP = 0x0000000000000000 15:30:44 FILEP = 0x0000000000000000 15:30:44 Raw hex dump of stack located in /opt/informix/tmp/af.90394.rawstk 15:30:44 Stack for thread: 0 idle base: 0x0000000001d2f800 len: 32768 pc: 0x00000000013f71a7 tos: 0x0000000001d368c0 state: running vp: 9 0x00000000013f71a7 (/opt/informix/bin/oninit) afstack 0x00000000013fa2b7 (/opt/informix/bin/oninit) afhandler 0x00000000013fa552 (/opt/informix/bin/oninit) afcrash_interface 0x000000000139ab15 (/opt/informix/bin/oninit) P 0x00000000013ab86d (/opt/informix/bin/oninit) idle_processor 0x00000000013bbd18 (/opt/informix/bin/oninit) startup siginfo: <NULL> 15:30:44 See Also: /opt/informix/tmp/af.90394 15:30:44 sh /opt/informix/etc/evidence.sh 3 0 /opt/informix/tmp/af.90394 0 0x0 0 0x1d2f5a0 9345 0 0 0 0 15:30:44 ------------------ End of assertion failure 0 ----------------- 15:30:44 Thread ID 0 will NOT be suspended because it is deemed too critical to the server. 15:30:44 See Also: /opt/informix/tmp/af.90394, shmem.90394.0 15:30:45 Starting crash time check of: 15:30:45 1. memory block headers 15:30:45 2. stacks 15:30:45 Starting check of memory blocks 15:30:45 15:30:45 Finished check of memory blocks 15:30:45 15:30:45 Starting check of stacks 15:30:45 15:30:45 Finished check of stacks 15:30:45 15:30:45 Crash time checking found no problems 15:30:45 15:30:45 ------------------ End of assertion failure 0 ----------------- -------
I haven't seen this behavior in 12.10.FC5W1. I would call IBM and open a PMR. Art Art S. Kagel, President and Principal Consultant ASK Database Management www.askdbmgt.com Blog: http://informix-myview.blogspot.com/ Disclaimer: Please keep in mind that my own opinions are my own opinions and do not reflect on the IIUG, nor any other organization with which I am associated either explicitly, implicitly, or by inference. Neither do those opinions reflect those of other individuals affiliated with any entity with which I am affiliated nor those of the entities themselves. On Sun, Feb 7, 2016 at 5:44 AM, FLORIAN APOLLONER <florian.apolloner@bap.at> wrote: > I just installed IDS 12.10 on CentOS7 and get random segfaults. During the > time it crashes I am not doing anything aside from running just a "select * > from table" for test purposes and maybe a "load from insert into". That > said > I cannot exactly correlate any of the queries to the segfault. Selinux is > set > to permissive. I've added what I could gather from log files, but I am > somewhat out of ides. Any hints on how to debug this? > > Thanks, > Florian > > Instance log: > ----- > 15:30:44 IBM Informix Dynamic Server Version 12.10.FC5W1WE > 15:30:44 Who: Thread(0, idle, 0, 9) > > File: mt.c Line: 1554 > 15:30:44 stack trace for pid 15723 written to /opt/informix/tmp/af.90394 > 15:30:44 See Also: /opt/informix/tmp/af.90394 > 15:30:44 Thread ID 0 will NOT be suspended because > > it is deemed too critical to the server. > 15:30:44 See Also: /opt/informix/tmp/af.90394, shmem.90394.0 > 15:30:45 Starting crash time check of: > 15:30:45 1. memory block headers > 15:30:45 2. stacks > 15:30:45 Crash time checking found no problems > 15:30:45 mt.c, line 1554, thread 0, proc id 15723, semop: errno = 43 > ------ > > af.90394: > ------ > 15:30:44 > 15:30:44 IBM Informix Dynamic Server Version 12.10.FC5W1WE Software Serial > Number AAA#B000000 > > 15:30:44 Assert Failed: semop: errno = 43 > > 15:30:44 Who: Thread(0, idle, 0, 9) > > File: mt.c Line: 1554 > 15:30:44 SHM Globals and Master Pool/Master Block Adresses: > > 15:30:44 shmcb = 0x000000004401a418 > 15:30:44 rhead = 0x0000000044086800 > 15:30:44 pool list = 0x000000004401a4f0 > 15:30:44 block pool list = 0x00000000440810f8 > 15:30:44 TRANSP = 0x0000000045194800 > 15:30:44 PARTP = 0x0000000000000000 > 15:30:44 PARTNP = 0x0000000000000000 > 15:30:44 OPENP = 0x0000000000000000 > 15:30:44 FILEP = 0x0000000000000000 > 15:30:44 Raw hex dump of stack located in /opt/informix/tmp/af.90394.rawstk > 15:30:44 Stack for thread: 0 idle > > base: 0x0000000001d2f800 > len: 32768 > > pc: 0x00000000013f71a7 > tos: 0x0000000001d368c0 > state: running > > vp: 9 > > 0x00000000013f71a7 (/opt/informix/bin/oninit) afstack > 0x00000000013fa2b7 (/opt/informix/bin/oninit) afhandler > 0x00000000013fa552 (/opt/informix/bin/oninit) afcrash_interface > 0x000000000139ab15 (/opt/informix/bin/oninit) P > 0x00000000013ab86d (/opt/informix/bin/oninit) idle_processor > 0x00000000013bbd18 (/opt/informix/bin/oninit) startup > > siginfo: <NULL> > > 15:30:44 See Also: /opt/informix/tmp/af.90394 > 15:30:44 sh /opt/informix/etc/evidence.sh 3 0 /opt/informix/tmp/af.90394 0 > 0x0 > 0 0x1d2f5a0 9345 0 0 0 0 > 15:30:44 > ------------------ End of assertion failure 0 ----------------- > > 15:30:44 Thread ID 0 will NOT be suspended because > > it is deemed too critical to the server. > 15:30:44 See Also: /opt/informix/tmp/af.90394, shmem.90394.0 > 15:30:45 Starting crash time check of: > 15:30:45 1. memory block headers > 15:30:45 2. stacks > 15:30:45 Starting check of memory blocks > 15:30:45 > 15:30:45 Finished check of memory blocks > 15:30:45 > 15:30:45 Starting check of stacks > 15:30:45 > 15:30:45 Finished check of stacks > 15:30:45 > 15:30:45 Crash time checking found no problems > 15:30:45 > 15:30:45 > ------------------ End of assertion failure 0 ----------------- > ------- > > > > ******************************************************************************* > Forum Note: Use "Reply" to post a response in the discussion forum. > > --089e013a2268d1d5c2052b2c37c1
Werre the kernel paramters set correctly? http://www.smooth1.co.uk/installs/dbinstalls.html#4.4.2 Regards, David, > On 07 February 2016 at 11:16 Art Kagel <art.kagel@gmail.com> wrote: > > > I haven't seen this behavior in 12.10.FC5W1. I would call IBM and open a > PMR. > > Art > > Art S. Kagel, President and Principal Consultant > ASK Database Management > www.askdbmgt.com > > Blog: http://informix-myview.blogspot.com/ > > Disclaimer: Please keep in mind that my own opinions are my own opinions > and do not reflect on the IIUG, nor any other organization with which I am > associated either explicitly, implicitly, or by inference. Neither do > those opinions reflect those of other individuals affiliated with any > entity with which I am affiliated nor those of the entities themselves. > > On Sun, Feb 7, 2016 at 5:44 AM, FLORIAN APOLLONER <florian.apolloner@bap.at> > wrote: > > > I just installed IDS 12.10 on CentOS7 and get random segfaults. During the > > time it crashes I am not doing anything aside from running just a "select * > > from table" for test purposes and maybe a "load from insert into". That > > said > > I cannot exactly correlate any of the queries to the segfault. Selinux is > > set > > to permissive. I've added what I could gather from log files, but I am > > somewhat out of ides. Any hints on how to debug this? > > > > Thanks, > > Florian > > > > Instance log: > > ----- > > 15:30:44 IBM Informix Dynamic Server Version 12.10.FC5W1WE > > 15:30:44 Who: Thread(0, idle, 0, 9) > > > > File: mt.c Line: 1554 > > 15:30:44 stack trace for pid 15723 written to /opt/informix/tmp/af.90394 > > 15:30:44 See Also: /opt/informix/tmp/af.90394 > > 15:30:44 Thread ID 0 will NOT be suspended because > > > > it is deemed too critical to the server. > > 15:30:44 See Also: /opt/informix/tmp/af.90394, shmem.90394.0 > > 15:30:45 Starting crash time check of: > > 15:30:45 1. memory block headers > > 15:30:45 2. stacks > > 15:30:45 Crash time checking found no problems > > 15:30:45 mt.c, line 1554, thread 0, proc id 15723, semop: errno = 43 > > ------ > > > > af.90394: > > ------ > > 15:30:44 > > 15:30:44 IBM Informix Dynamic Server Version 12.10.FC5W1WE Software Serial > > Number AAA#B000000 > > > > 15:30:44 Assert Failed: semop: errno = 43 > > > > 15:30:44 Who: Thread(0, idle, 0, 9) > > > > File: mt.c Line: 1554 > > 15:30:44 SHM Globals and Master Pool/Master Block Adresses: > > > > 15:30:44 shmcb = 0x000000004401a418 > > 15:30:44 rhead = 0x0000000044086800 > > 15:30:44 pool list = 0x000000004401a4f0 > > 15:30:44 block pool list = 0x00000000440810f8 > > 15:30:44 TRANSP = 0x0000000045194800 > > 15:30:44 PARTP = 0x0000000000000000 > > 15:30:44 PARTNP = 0x0000000000000000 > > 15:30:44 OPENP = 0x0000000000000000 > > 15:30:44 FILEP = 0x0000000000000000 > > 15:30:44 Raw hex dump of stack located in /opt/informix/tmp/af.90394.rawstk > > 15:30:44 Stack for thread: 0 idle > > > > base: 0x0000000001d2f800 > > len: 32768 > > > > pc: 0x00000000013f71a7 > > tos: 0x0000000001d368c0 > > state: running > > > > vp: 9 > > > > 0x00000000013f71a7 (/opt/informix/bin/oninit) afstack > > 0x00000000013fa2b7 (/opt/informix/bin/oninit) afhandler > > 0x00000000013fa552 (/opt/informix/bin/oninit) afcrash_interface > > 0x000000000139ab15 (/opt/informix/bin/oninit) P > > 0x00000000013ab86d (/opt/informix/bin/oninit) idle_processor > > 0x00000000013bbd18 (/opt/informix/bin/oninit) startup > > > > siginfo: <NULL> > > > > 15:30:44 See Also: /opt/informix/tmp/af.90394 > > 15:30:44 sh /opt/informix/etc/evidence.sh 3 0 /opt/informix/tmp/af.90394 0 > > 0x0 > > 0 0x1d2f5a0 9345 0 0 0 0 > > 15:30:44 > > ------------------ End of assertion failure 0 ----------------- > > > > 15:30:44 Thread ID 0 will NOT be suspended because > > > > it is deemed too critical to the server. > > 15:30:44 See Also: /opt/informix/tmp/af.90394, shmem.90394.0 > > 15:30:45 Starting crash time check of: > > 15:30:45 1. memory block headers > > 15:30:45 2. stacks > > 15:30:45 Starting check of memory blocks > > 15:30:45 > > 15:30:45 Finished check of memory blocks > > 15:30:45 > > 15:30:45 Starting check of stacks > > 15:30:45 > > 15:30:45 Finished check of stacks > > 15:30:45 > > 15:30:45 Crash time checking found no problems > > 15:30:45 > > 15:30:45 > > ------------------ End of assertion failure 0 ----------------- > > ------- > > > > > > > > > ******************************************************************************* > > Forum Note: Use "Reply" to post a response in the discussion forum. > > > > > > --089e013a2268d1d5c2052b2c37c1 > > > ******************************************************************************* > Forum Note: Use "Reply" to post a response in the discussion forum. >
I have: ipcs -l ------ Messages Limits -------- max queues system wide = 7065 max size of message (bytes) = 8192 default max size of queue (bytes) = 16384 ------ Shared Memory Limits -------- max number of segments = 4096 max seg size (kbytes) = 18014398509465599 max total shared memory (kbytes) = 18014398442373116 min seg size (bytes) = 1 ------ Semaphore Limits -------- max number of arrays = 128 max semaphores per array = 250 max semaphores system wide = 32000 max ops per semop call = 32 semaphore max value = 32767 [root@ids01 ~]# sysctl -a|grep kernel.sem kernel.sem = 250 32000 32 128 kernel.sem_next_id = -1 [root@ids01 ~]# sysctl -a|grep kernel.shm kernel.shm_next_id = -1 kernel.shm_rmid_forced = 0 kernel.shmall = 18446744073692774399 kernel.shmmax = 18446744073692774399 kernel.shmmni = 4096 According to the release notes, I should have SEMMSL set to at least 100 (I have 250, so that should be fine?)
I've adjusted my values to the suggested values from the link, let's see if it becomes more stable. That said, once the server crashes, table data is lost (data which was written hours ago). Shouldn't that all have been written to disk by now? how can I check that? Thanks, Florian
Are the databases logged and set to UNBUFFERED LOG or ANSI mode? If they are, then yes, recovery should complete any transactions that were committed. If you have BUFFERED LOG then it is possible that the COMMIT records were still sitting unwritten in the logical log buffers when the server crashed so those transactions would have been rolled back during fast recovery. Obviously if your databases are not logged or there were uncommitted transactions against logged databases, then the former would be partially on disk and the latter would have been rolled back. Art Art S. Kagel, President and Principal Consultant ASK Database Management www.askdbmgt.com Blog: http://informix-myview.blogspot.com/ Disclaimer: Please keep in mind that my own opinions are my own opinions and do not reflect on the IIUG, nor any other organization with which I am associated either explicitly, implicitly, or by inference. Neither do those opinions reflect those of other individuals affiliated with any entity with which I am affiliated nor those of the entities themselves. On Sun, Feb 7, 2016 at 8:26 AM, FLORIAN APOLLONER <florian.apolloner@bap.at> wrote: > I've adjusted my values to the suggested values from the link, let's see > if it > becomes more stable. > > That said, once the server crashes, table data is lost (data which was > written > hours ago). Shouldn't that all have been written to disk by now? how can I > check that? > > Thanks, > Florian > > > > ******************************************************************************* > Forum Note: Use "Reply" to post a response in the discussion forum. > > --047d7bfe9fe8ba800b052b2e8274
Hi Art, the database is unlogged (I am just toying around with it) -- but even then, at same point the data has to end up at the disk, can I somehow force informix to write everything down? Thanks, Florian
onstat -b | grep modified to check for modified buffers
onmode -c to perform a hard checkpoint
The error you are getting is errno 43 = EIDRM Identifier removed
Is something removing shared memory segments or semaphores?
Is there more than 1 Informix instance on this machine? - onstat -g dis
Is there anything in /var/log/messages?
http://www-01.ibm.com/support/docview.wss?uid=swg27013343 mentions 12.10.FC6
can
you test with that version instead?
Regards,
David.
> On 07 February 2016 at 14:25 FLORIAN APOLLONER <florian.apolloner@bap.at>
> wrote:
>
>
> Hi Art,
>
> the database is unlogged (I am just toying around with it) -- but even then,
> at same point the data has to end up at the disk, can I somehow force
informix
> to write everything down?
>
> Thanks,
> Florian
>
>
>
*******************************************************************************
> Forum Note: Use "Reply" to post a response in the discussion forum.
>
The only way is to force a checkpoint. Art On Feb 7, 2016 9:26 AM, "FLORIAN APOLLONER" <florian.apolloner@bap.at> wrote: > Hi Art, > > the database is unlogged (I am just toying around with it) -- but even > then, > at same point the data has to end up at the disk, can I somehow force > informix > to write everything down? > > Thanks, > Florian > > > > ******************************************************************************* > Forum Note: Use "Reply" to post a response in the discussion forum. > > --001a113f8f8ed196c2052b2efada
Perform a transaction which does an update and also is using unbuffered
logging. You only need to flush the logs to ensure that activity is recovered.
If you really want to flush everything to disk, then run onmode -c which will
cause a checkpoint to be performed.
Madison Pruet
Retired and Loving it
On Sunday, February 7, 2016 8:26 AM, FLORIAN APOLLONER
<florian.apolloner@bap.at> wrote:
Hi Art,
the database is unlogged (I am just toying around with it) -- but even then,
at same point the data has to end up at the disk, can I somehow force informix
to write everything down?
Thanks,
Florian
*******************************************************************************
Forum Note: Use "Reply" to post a response in the discussion forum.
Hi David,
On 07.02.2016 15:32, david@smooth1.co.uk wrote:
>
> onstat -b | grep modified to check for modified buffers>
> onmode -c to perform a hard checkpoint
That is good to know, thank you very much!
> Is something removing shared memory segments or semaphores?
Not that I would know of.
> Is there more than 1 Informix instance on this machine? - onstat -g dis
Nope, this is literally a blank CentOS install with just one informix
install and just one instance.
> Is there anything in /var/log/messages?
Nope
> http://www-01.ibm.com/support/docview.wss?uid=swg27013343 mentions 12.10.FC6
can
> you test with that version instead?
I'll try and see if our license covers that, guess I'll be calling IBM
tomorrow.
Thanks,
Florian
Hi Art and David, after applying the kernel parameters, the database is still crashing. I will update & open a bug report at IBM. Thank you so far and I'll report back as soon as I know more. Cheers, Florian
Get 12.10.FC6X5 from Fix Central: the root offset bug in 12.10.FC6 is quite nasty; it's only safe to use this version id ROOTOFFSET is 0 in your onconfig. Ben.
There is an APAR that can cause a semaphore array to be removed from a running instance by onclean where there are two or more instances running: APAR IT09608: ONCLEAN CAN REMOVE RESOURCES OF ANOTHER INSTANCE AND ACCIDENTALLY BRING THIS WRONG INSTANCE DOWN This is partly because the shared memory id is a function of SERVERNUM but the semaphore ids get allocated in order. If the instances started in a different order to the previous occasion it's possible for the information for onclean to be incorrect. This is only possible where there are two or more instances on the same machine, which is not the case here. However given it is "errno = 43" I would have a hunt around the system for any scripts that call ipcrm or onclean. Ben.
Hi Ben, I only have one instance running. Our support contact suggested to try and set "RemoveIPC=no" in logind.conf for systemd. I think this sounds like a plausible cause for the behaviour we are seeing on the test instances. I'll keep you updated! Cheers, Florian
Florian, Interesting. It looks like a very likely candidate. There is an Oracle tech note on this: https://docs.oracle.com/cd/E52668_01/E67200/html/section-t51_kcn_f5.html I also found some articles related to Postgres about the same problem. Ben.
Hi Ben, On 08.02.2016 14:37, BENJAMIN THOMPSON wrote: > https://docs.oracle.com/cd/E52668_01/E67200/html/section-t51_kcn_f5.html Good find, most importantly they write: "is terminated for a non-system user's processes" -- my informix user has id 1000, ie the first non-system user. So another fix would probably be to ensure that this user has id < 500. Cheers, Florian
Okay, I was able to verify that RemoveIPC=no actually fixes it. To reproduce
(if someone else runs into this ever :D). Make sure you have RemoveIPC=yes set
and use the following systemd.d service file to start informix (adjust as
needed):
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
[Unit]
Description=Informix DB Service
[Service]
Type=forking
User=informix
EnvironmentFile=/opt/informix/ids01.ksh
ExecStart=/opt/informix/bin/oninit -y
ExecStop=/opt/informix/bin/onmode -ky
[Install]
WantedBy=multi-user.target
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
It is very important that you start Informix like this and not manually via
oninit! Verify with loginctl that there is no running session for the user
informix. Login as user informix and verify that you have a session in
loginctl, log out and watch your database crash [1].
[1] Note: Ensure that you are not using SSH ControlMaster or so which could
keep your session open for way longer, verify that with loginctl
session-status <id> if your database does not crash :D
Thanks to all of you!
Cheers,
Florian
Related threads
- onbar -c -F in Windows Informix instance
- Anyone... SQLCODE=-668, ISAM error=-1
- Not using the 100% logical log page size alloacted to informix