Dev Server Won't Start
Posted in 2018
A 11.50.FC9DE Developer Edition dev server refused to start: oninit reported "Fatal error in shared memory initialization" and onclean -ky didn't help. Running oninit -v pinpointed the failure at "Checking database partition index...FAILED". Respondents suggested this usually follows an incomplete or physical-only restore, pointed to an IBM technote, and asked for more online.log. The log showed the original crash was an assert in the HDR log-apply thread (hdrPrim.c line 1841) that panicked the server. Contributors then asked for the af.* stack trace function names, but the thread ends there with no resolution recorded.
Auto-generated by DrWatson from the posts below — may be imperfect; read the full thread.
Topics: Logging & Checkpoints
Does anyone see anything in this message log that tells me what is wrong? It
fails on oninit and says check the message log. I have tried onclean -ky
multiple times as I thought it was a shared memory issue
[informix@DB1 ~]$ onstat -
shared memory not initialized for INFORMIXSERVER 'newserver'
[informix@DB1 ~]$ oninit
WARNING: server initialization failed, or possibly timed out (if -w was used).
Check the message log, online.log, for errors.
[informix@DB1 ~]$ onstat -m
shared memory not initialized for INFORMIXSERVER 'newserver'
Message Log File: /opt/informix/11.5/newserver_online.log
12:10:40 DR: Turned off on primary server
12:10:40 Physical Recovery Started at Page (1:12906).
12:10:40 Physical Recovery Complete: 0 Pages Examined, 0 Pages Restored.
12:10:40 Logical Recovery Started.
12:10:40 10 recovery worker threads will be started.
12:10:40 Logical Recovery has reached the transaction cleanup phase.
12:10:40 Checkpoint Completed: duration was 0 seconds.
12:10:40 Thu Feb 1 - loguniq 53, logpos 0x8018, timestamp: 0x40dd68 Interval:
4970
12:10:40 Maximum server connections 0
12:10:40 Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked 0,
Plog used 0, Llog used 1
12:10:40 Logical Recovery Complete.
0 Committed, 1 Rolled Back, 0 Open, 0 Bad Locks
12:10:41 oninit: Fatal error in shared memory initialization
12:10:41 IBM Informix Dynamic Server Stopped.
12:10:41 mt_shm_remove: WARNING: may not have removed all/correct segments
run with the -v option. (verbose)
oninit -v
j.
> On Feb 2, 2018, at 9:38 AM, BENJI LONG <ruggedmouse@hotmail.com> wrote:
>
> Does anyone see anything in this message log that tells me what is wrong? It
> fails on oninit and says check the message log. I have tried onclean -ky
> multiple times as I thought it was a shared memory issue
>
> [informix@DB1 ~]$ onstat -
> shared memory not initialized for INFORMIXSERVER 'newserver'
> [informix@DB1 ~]$ oninit
>
> WARNING: server initialization failed, or possibly timed out (if -w was
used).
> Check the message log, online.log, for errors.
> [informix@DB1 ~]$ onstat -m
> shared memory not initialized for INFORMIXSERVER 'newserver'
>
> Message Log File: /opt/informix/11.5/newserver_online.log
> 12:10:40 DR: Turned off on primary server
> 12:10:40 Physical Recovery Started at Page (1:12906).
> 12:10:40 Physical Recovery Complete: 0 Pages Examined, 0 Pages Restored.
> 12:10:40 Logical Recovery Started.
> 12:10:40 10 recovery worker threads will be started.
> 12:10:40 Logical Recovery has reached the transaction cleanup phase.
> 12:10:40 Checkpoint Completed: duration was 0 seconds.
> 12:10:40 Thu Feb 1 - loguniq 53, logpos 0x8018, timestamp: 0x40dd68 Interval:
> 4970
>
> 12:10:40 Maximum server connections 0
> 12:10:40 Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked 0,
> Plog used 0, Llog used 1
>
> 12:10:40 Logical Recovery Complete.
>
> 0 Committed, 1 Rolled Back, 0 Open, 0 Bad Locks
>
> 12:10:41 oninit: Fatal error in shared memory initialization
>
> 12:10:41 IBM Informix Dynamic Server Stopped.
>
> 12:10:41 mt_shm_remove: WARNING: may not have removed all/correct segments
>
>
>
*******************************************************************************
> Forum Note: Use "Reply" to post a response in the discussion forum.
>
Would need more context. Can you post 'tail -200 /opt/informix/11.5/newserver_online.log' ? And also the last 50 or so lines of when the server last was running and coming down.
It says Checking database partition index...FAILED
[informix@DB1 ~]$ onstat -
shared memory not initialized for INFORMIXSERVER 'newserver'
[informix@DB1 ~]$ oninit -v
Checking group membership to determine server run mode...succeeded
Reading configuration file '/opt/informix/11.5/etc/onconfig.1'...succeeded
Creating /INFORMIXTMP/.infxdirs...succeeded
Checking config parameters...succeeded
Allocating and attaching to shared memory...succeeded
Creating resident pool 14710 kbytes...succeeded
Allocating 100016 kbytes for buffer pool of 2K page size...succeeded
Creating infos file "/opt/informix/11.5/etc/.infos.newserver"...succeeded
Linking conf file "/opt/informix/11.5/etc/.conf.newserver"...succeeded
Initializing rhead structure...succeeded
Writing to infos file...succeeded
Initialization of Encryption...succeeded
Initializing ASF...succeeded
Initializing Dictionary Cache and SPL Routine Cache...succeeded
Bringing up ADM VP...succeeded
Creating VP classes...succeeded
Onlining 0 additional cpu vps...succeeded
Onlining 2 IO vps...succeeded
Forking main_loop thread...succeeded
Initializing DR structures...succeeded
Forking 1 'ipcshm' listener threads...succeeded
Forking 1 'soctcp' listener threads...succeeded
Starting tracing...succeeded
Initializing 8 flushers...succeeded
Initializing SDS Server network connections...succeeded
Initializing log/checkpoint information...succeeded
Initializing dbspaces...succeeded
Opening primary chunks...succeeded
Opening mirror chunks...succeeded
Validating chunks...succeeded
Initialize Async Log Flusher...succeeded
Starting B-tree Scanner...succeeded
Initializing DBSPACETEMP list...succeeded
Checking database partition index...FAILED
oninit: Fatal error in shared memory initialization
WARNING: server initialization failed, or possibly timed out (if -w was used).
Check the message log, online.log, for errors.
Was there a restore done on this server which did not complete successfully?
That is the most common reason I have seen for this message.
Regards,
David.
> On 02 February 2018 at 15:07 BENJI LONG <ruggedmouse@hotmail.com> wrote:
>
>
> It says Checking database partition index...FAILED
>
> [informix@DB1 ~]$ onstat -
> shared memory not initialized for INFORMIXSERVER 'newserver'
> [informix@DB1 ~]$ oninit -v
> Checking group membership to determine server run mode...succeeded
> Reading configuration file '/opt/informix/11.5/etc/onconfig.1'...succeeded
> Creating /INFORMIXTMP/.infxdirs...succeeded
> Checking config parameters...succeeded
> Allocating and attaching to shared memory...succeeded
> Creating resident pool 14710 kbytes...succeeded
> Allocating 100016 kbytes for buffer pool of 2K page size...succeeded
> Creating infos file "/opt/informix/11.5/etc/.infos.newserver"...succeeded
> Linking conf file "/opt/informix/11.5/etc/.conf.newserver"...succeeded
> Initializing rhead structure...succeeded
> Writing to infos file...succeeded
> Initialization of Encryption...succeeded
> Initializing ASF...succeeded
> Initializing Dictionary Cache and SPL Routine Cache...succeeded
> Bringing up ADM VP...succeeded
> Creating VP classes...succeeded
> Onlining 0 additional cpu vps...succeeded
> Onlining 2 IO vps...succeeded
> Forking main_loop thread...succeeded
> Initializing DR structures...succeeded
> Forking 1 'ipcshm' listener threads...succeeded
> Forking 1 'soctcp' listener threads...succeeded
> Starting tracing...succeeded
> Initializing 8 flushers...succeeded
> Initializing SDS Server network connections...succeeded
> Initializing log/checkpoint information...succeeded
> Initializing dbspaces...succeeded
> Opening primary chunks...succeeded
> Opening mirror chunks...succeeded
> Validating chunks...succeeded
> Initialize Async Log Flusher...succeeded
> Starting B-tree Scanner...succeeded
> Initializing DBSPACETEMP list...succeeded
> Checking database partition index...FAILED
> oninit: Fatal error in shared memory initialization
>
> WARNING: server initialization failed, or possibly timed out (if -w was
used).
> Check the message log, online.log, for errors.
>
>
>
*******************************************************************************
> Forum Note: Use "Reply" to post a response in the discussion forum.
>
http://www-01.ibm.com/support/docview.wss?uid=3Dswg21164566 =
<http://www-01.ibm.com/support/docview.wss?uid=3Dswg21164566>
cheers
j.
> On Feb 2, 2018, at 10:07 AM, BENJI LONG <ruggedmouse@hotmail.com> =
wrote:
>=20
> It says Checking database partition index...FAILED=20
>=20
> [informix@DB1 ~]$ onstat -=20
> shared memory not initialized for INFORMIXSERVER 'newserver'=20
> [informix@DB1 ~]$ oninit -v=20
> Checking group membership to determine server run mode...succeeded=20
> Reading configuration file =
'/opt/informix/11.5/etc/onconfig.1'...succeeded=20
> Creating /INFORMIXTMP/.infxdirs...succeeded=20
> Checking config parameters...succeeded=20
> Allocating and attaching to shared memory...succeeded=20
> Creating resident pool 14710 kbytes...succeeded=20
> Allocating 100016 kbytes for buffer pool of 2K page size...succeeded=20=
> Creating infos file =
"/opt/informix/11.5/etc/.infos.newserver"...succeeded=20
> Linking conf file "/opt/informix/11.5/etc/.conf.newserver"...succeeded=20=
> Initializing rhead structure...succeeded=20
> Writing to infos file...succeeded=20
> Initialization of Encryption...succeeded=20
> Initializing ASF...succeeded=20
> Initializing Dictionary Cache and SPL Routine Cache...succeeded=20
> Bringing up ADM VP...succeeded=20
> Creating VP classes...succeeded=20
> Onlining 0 additional cpu vps...succeeded=20
> Onlining 2 IO vps...succeeded=20
> Forking main_loop thread...succeeded=20
> Initializing DR structures...succeeded=20
> Forking 1 'ipcshm' listener threads...succeeded=20
> Forking 1 'soctcp' listener threads...succeeded=20
> Starting tracing...succeeded=20
> Initializing 8 flushers...succeeded=20
> Initializing SDS Server network connections...succeeded=20
> Initializing log/checkpoint information...succeeded=20
> Initializing dbspaces...succeeded=20
> Opening primary chunks...succeeded=20
> Opening mirror chunks...succeeded=20
> Validating chunks...succeeded=20
> Initialize Async Log Flusher...succeeded=20
> Starting B-tree Scanner...succeeded=20
> Initializing DBSPACETEMP list...succeeded=20
> Checking database partition index...FAILED=20
> oninit: Fatal error in shared memory initialization=20
>=20
> WARNING: server initialization failed, or possibly timed out (if -w =
was used).=20
> Check the message log, online.log, for errors.=20
>=20
>=20
> =
**************************************************************************=
*****=20
> Forum Note: Use "Reply" to post a response in the discussion forum.=20=
>=20
.... or a physical-only restore ... or incomplete logical restore.
What also looks confused is the Checkpoint message coming before the "
Logical Recovery Complete." message.
Still would like to see more online.log.
From: "david@smooth1.co.uk" <david@smooth1.co.uk>
To: ids@iiug.org
Date: 02/02/2018 04:12 PM
Subject: Re: Dev Server Won't Start [40646]
Sent by: ids-bounces@iiug.org
Was there a restore done on this server which did not complete
successfully?
That is the most common reason I have seen for this message.
Regards,
David.
> On 02 February 2018 at 15:07 BENJI LONG <ruggedmouse@hotmail.com> wrote:
>
>
> It says Checking database partition index...FAILED
>
> [informix@DB1 ~]$ onstat -
> shared memory not initialized for INFORMIXSERVER 'newserver'
> [informix@DB1 ~]$ oninit -v
> Checking group membership to determine server run mode...succeeded
> Reading configuration file
'/opt/informix/11.5/etc/onconfig.1'...succeeded
> Creating /INFORMIXTMP/.infxdirs...succeeded
> Checking config parameters...succeeded
> Allocating and attaching to shared memory...succeeded
> Creating resident pool 14710 kbytes...succeeded
> Allocating 100016 kbytes for buffer pool of 2K page size...succeeded
> Creating infos file "/opt/informix/11.5/etc/.infos.newserver"...succeeded
> Linking conf file "/opt/informix/11.5/etc/.conf.newserver"...succeeded
> Initializing rhead structure...succeeded
> Writing to infos file...succeeded
> Initialization of Encryption...succeeded
> Initializing ASF...succeeded
> Initializing Dictionary Cache and SPL Routine Cache...succeeded
> Bringing up ADM VP...succeeded
> Creating VP classes...succeeded
> Onlining 0 additional cpu vps...succeeded
> Onlining 2 IO vps...succeeded
> Forking main_loop thread...succeeded
> Initializing DR structures...succeeded
> Forking 1 'ipcshm' listener threads...succeeded
> Forking 1 'soctcp' listener threads...succeeded
> Starting tracing...succeeded
> Initializing 8 flushers...succeeded
> Initializing SDS Server network connections...succeeded
> Initializing log/checkpoint information...succeeded
> Initializing dbspaces...succeeded
> Opening primary chunks...succeeded
> Opening mirror chunks...succeeded
> Validating chunks...succeeded
> Initialize Async Log Flusher...succeeded
> Starting B-tree Scanner...succeeded
> Initializing DBSPACETEMP list...succeeded
> Checking database partition index...FAILED
> oninit: Fatal error in shared memory initialization
>
> WARNING: server initialization failed, or possibly timed out (if -w was
used).
> Check the message log, online.log, for errors.
>
>
>
*******************************************************************************
> Forum Note: Use "Reply" to post a response in the discussion forum.
>
*******************************************************************************
Forum Note: Use "Reply" to post a response in the discussion forum.
hmmm, maybe one of the other DBA's was in there trying something and didn't tell me. Thanks, I will follow up with him before trying anything else.
This looks like where it all went bad:
11:47:14 Checkpoint Completed: duration was 0 seconds.
11:47:14 Thu Feb 1 - loguniq 52, logpos 0x119a018, timestamp: 0x40be63
Interval: 4965
11:47:14 Maximum server connections 0
11:47:14 Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked 0,
Plog used 0, Llog used 0
11:57:42 DR_ERR set to -1
11:57:42 Assert Failed: DR: Log Record Apply Thread Exited Abnormally.
Internal Error.
A restart of the database server shall be required to correct
this problem.
11:57:42 IBM Informix Dynamic Server Version 11.50.FC9DE
11:57:42 Who: Session(17, informix@, 0, 0x4b86db78)
Thread(33, dr_prapply, 4b82f4f8, 1)
File: hdr/hdrPrim.c Line: 1841
11:57:42 Results: Dynamic Server must abort
11:57:42 Action: Reinitialize shared memory
11:57:42 stack trace for pid 16817 written to /opt/informix/11.5/tmp/af.40938f6
11:57:42 See Also: /opt/informix/11.5/tmp/af.40938f6, shmem.40938f6.0
11:57:44 Starting crash time check of:
11:57:44 1. memory block headers
11:57:44 2. stacks
11:57:44 Crash time checking found no problems
11:57:44 hdr/hdrPrim.c, line 1841, thread 33, proc id 16817, DR: Log Record
Apply Thread Exited Abnormally. Internal Error.
A restart of the database server shall be required to correct
this problem.
.
11:57:44 The Master Daemon Died
11:57:44 PANIC: Attempting to bring system down
11:59:06 IBM Informix Dynamic Server Started.
11:59:06 Warning: The IBM IDS Developer Edition license restriction limits
11:59:06 the total shared memory size for this server to 1048576 KB.
11:59:06 The maximum allowable shared memory was reset to this size to start
the database server.
Thu Feb 1 11:59:08 2018
11:59:08 Event alarms enabled. ALARMPROG =
'/opt/informix/11.5/etc/alarmprogram.sh'
11:59:08 Booting Language <c> from module <>
11:59:08 Loading Module <CNULL>
11:59:08 Booting Language <builtin> from module <>
11:59:08 Loading Module <BUILTINNULL>
11:59:14 DR: DRAUTO is 1 (Retain)
11:59:14 DR: ENCRYPT_HDR is 0 (HDR encryption Disabled)
11:59:14 Event notification facility epoll enabled.
11:59:14 IBM Informix Dynamic Server Version 11.50.FC9DE Software Serial
Number AAA#B000000
11:59:15 IBM Informix Dynamic Server Initialized -- Shared Memory Initialized.
11:59:15 Started 1 B-tree scanners.
11:59:15 B-tree scanner threshold set at 5000.
11:59:15 B-tree scanner range scan size set to -1.
11:59:15 B-tree scanner ALICE mode set to 6.
11:59:15 B-tree scanner index compression level set to med.
11:59:15 DR: Reservation of the last logical log for log backup turned on
11:59:15 DR: Trying to connect to secondary server = newservers_hdr
11:59:15 DR: Cannot connect to secondary server
11:59:15 DR: Turned off on primary server
11:59:15 Physical Recovery Started at Page (1:12648).
11:59:15 Physical Recovery Complete: 252 Pages Examined, 252 Pages Restored.
11:59:15 Logical Recovery Started.
11:59:15 10 recovery worker threads will be started.
11:59:15 Fast Recovery Switching to Log 53
11:59:16 Logical Recovery has reached the transaction cleanup phase.
11:59:16 Checkpoint Completed: duration was 0 seconds.
11:59:16 Thu Feb 1 - loguniq 53, logpos 0x18, timestamp: 0x40dd20 Interval:
4966
11:59:16 Maximum server connections 0
11:59:16 Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked 0,
Plog used 258, Llog used 1
11:59:16 Logical Recovery Complete.
442 Committed, 1 Rolled Back, 0 Open, 0 Bad Locks
11:59:17 oninit: Fatal error in shared memory initialization
11:59:17 IBM Informix Dynamic Server Stopped.
11:59:17 mt_shm_remove: WARNING: may not have removed all/correct segments
What is the stack trace in /opt/informix/11.5/tmp/af.40938f6?
Regards,
David.
> On 02 February 2018 at 15:52 BENJI LONG <ruggedmouse@hotmail.com> wrote:
>
>
> This looks like where it all went bad:
>
> 11:47:14 Checkpoint Completed: duration was 0 seconds.
> 11:47:14 Thu Feb 1 - loguniq 52, logpos 0x119a018, timestamp: 0x40be63
> Interval: 4965
>
> 11:47:14 Maximum server connections 0
> 11:47:14 Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked 0,
> Plog used 0, Llog used 0
>
> 11:57:42 DR_ERR set to -1
> 11:57:42 Assert Failed: DR: Log Record Apply Thread Exited Abnormally.
> Internal Error.
>
> A restart of the database server shall be required to correct
>
> this problem.
>
> 11:57:42 IBM Informix Dynamic Server Version 11.50.FC9DE
> 11:57:42 Who: Session(17, informix@, 0, 0x4b86db78)
>
> Thread(33, dr_prapply, 4b82f4f8, 1)
>
> File: hdr/hdrPrim.c Line: 1841
> 11:57:42 Results: Dynamic Server must abort
> 11:57:42 Action: Reinitialize shared memory
> 11:57:42 stack trace for pid 16817 written to
> /opt/informix/11.5/tmp/af.40938f6
> 11:57:42 See Also: /opt/informix/11.5/tmp/af.40938f6, shmem.40938f6.0
> 11:57:44 Starting crash time check of:
> 11:57:44 1. memory block headers
> 11:57:44 2. stacks
> 11:57:44 Crash time checking found no problems
> 11:57:44 hdr/hdrPrim.c, line 1841, thread 33, proc id 16817, DR: Log Record
> Apply Thread Exited Abnormally. Internal Error.
>
> A restart of the database server shall be required to correct
>
> this problem.
> ..
> 11:57:44 The Master Daemon Died
> 11:57:44 PANIC: Attempting to bring system down
> 11:59:06 IBM Informix Dynamic Server Started.
> 11:59:06 Warning: The IBM IDS Developer Edition license restriction limits
> 11:59:06 the total shared memory size for this server to 1048576 KB.
> 11:59:06 The maximum allowable shared memory was reset to this size to start
> the database server.
>
> Thu Feb 1 11:59:08 2018
>
> 11:59:08 Event alarms enabled. ALARMPROG =
> '/opt/informix/11.5/etc/alarmprogram.sh'
> 11:59:08 Booting Language <c> from module <>
> 11:59:08 Loading Module <CNULL>
> 11:59:08 Booting Language <builtin> from module <>
> 11:59:08 Loading Module <BUILTINNULL>
> 11:59:14 DR: DRAUTO is 1 (Retain)
> 11:59:14 DR: ENCRYPT_HDR is 0 (HDR encryption Disabled)
> 11:59:14 Event notification facility epoll enabled.
> 11:59:14 IBM Informix Dynamic Server Version 11.50.FC9DE Software Serial
> Number AAA#B000000
> 11:59:15 IBM Informix Dynamic Server Initialized -- Shared Memory
Initialized.
>
> 11:59:15 Started 1 B-tree scanners.
> 11:59:15 B-tree scanner threshold set at 5000.
> 11:59:15 B-tree scanner range scan size set to -1.
> 11:59:15 B-tree scanner ALICE mode set to 6.
> 11:59:15 B-tree scanner index compression level set to med.
> 11:59:15 DR: Reservation of the last logical log for log backup turned on
> 11:59:15 DR: Trying to connect to secondary server = newservers_hdr
> 11:59:15 DR: Cannot connect to secondary server
> 11:59:15 DR: Turned off on primary server
> 11:59:15 Physical Recovery Started at Page (1:12648).
> 11:59:15 Physical Recovery Complete: 252 Pages Examined, 252 Pages Restored.
> 11:59:15 Logical Recovery Started.
> 11:59:15 10 recovery worker threads will be started.
> 11:59:15 Fast Recovery Switching to Log 53
> 11:59:16 Logical Recovery has reached the transaction cleanup phase.
> 11:59:16 Checkpoint Completed: duration was 0 seconds.
> 11:59:16 Thu Feb 1 - loguniq 53, logpos 0x18, timestamp: 0x40dd20 Interval:
> 4966
>
> 11:59:16 Maximum server connections 0
> 11:59:16 Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked 0,
> Plog used 258, Llog used 1
>
> 11:59:16 Logical Recovery Complete.
>
> 442 Committed, 1 Rolled Back, 0 Open, 0 Bad Locks
>
> 11:59:17 oninit: Fatal error in shared memory initialization
>
> 11:59:17 IBM Informix Dynamic Server Stopped.
>
> 11:59:17 mt_shm_remove: WARNING: may not have removed all/correct segments
>
>
>
*******************************************************************************
> Forum Note: Use "Reply" to post a response in the discussion forum.
>
What am I looking for here in this file? The output is massive. Like 1000's of lines of code I think.
The list of function names within the code. Regards, David. > On 02 February 2018 at 19:37 BENJI LONG <ruggedmouse@hotmail.com> wrote: > > > What am I looking for here in this file? The output is massive. Like 1000's of > lines of code I think. > > > ******************************************************************************* > Forum Note: Use "Reply" to post a response in the discussion forum. >