Informix

Expand all | Collapse all

Fast Recovery after correct shutdown

  • 1.  Fast Recovery after correct shutdown

    Posted 9 days ago
    Hello,
    using IBM Informix Dynamic Server Version 14.10.FC3IE on Windows 10 Pro 64bit.

    I am a little confused reading my Informix log:

    16:33:34  IBM Informix Dynamic Server Stopped. 
    ... means, I hope, that instance was correctly stopped.

    I started the instance again...
    ...
    16:35:40  Physical Recovery Started at Page (9:149754).
    16:35:40  Physical Recovery Complete: 16 Pages Examined, 16 Pages Restored.
    16:35:40  Logical Recovery Started.
    16:35:40  5 recovery worker threads will be started.
    16:35:43  Logical Recovery has reached the transaction cleanup phase.
    16:35:43  Logical Recovery Complete.      0 Committed, 0 Rolled Back, 0 Open, 0 Bad Locks

    From the IBM Informix documentation (14.10):

    "As part of shared-memory initialization, the database server checks the contents of the physical log. The physical log is empty when the database server shuts down under control. The move from online mode to quiescent mode includes a checkpoint, which flushes the physical log. Therefore, if the database server finds pages in the physical log, the database server clearly went offline under uncontrolled conditions, and fast recovery begins."

    Why was Physical Recovery activated? What means 16 pages restored? 
    Data checked, no problems found.

    Thank you very much.

    Leos


  • 2.  RE: Fast Recovery after correct shutdown

    Posted 9 days ago
    Leos:

    Yes, if the restart performed a physical recovery that had to process more than zero pages then the engine was not shutdown normally. Assuming the Informix server did not crash, most likely, since this is a Windows system, the Informix server is not properly registered as a Service and so the shutdown script was not executed. Either that or the machine suffered from a hard power down.

    Art S. Kagel, President and Principal Consultant
    ASK Database Management


    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.








  • 3.  RE: Fast Recovery after correct shutdown

    Posted 9 days ago

    When the engine is down –what is the last line in the online.log ? If it is not  IBM Informix Dynamic Server Stopped then the engine was not shutdown properly

     

    Cheers

    Paul

     






  • 4.  RE: Fast Recovery after correct shutdown

    Posted 9 days ago
    Hi,

    Stopping:
    C:\Windows\system32>net stop ixlur
    Stopping service Informix IDS - ixlur.........
    Service Informix IDS - ixlur was succefully stopped.
    ========================================================================
    16:35:47  SCHAPI: Started 2 dbWorker threads.
    16:35:49  Defragmenter cleaner thread now running
    16:35:49  Defragmenter cleaner thread cleaned:0 partitions

    Wed May 20 01:00:08 2020

    01:00:08  Logical Log 74 Complete, timestamp: 0xde56af4.
    18:41:53  SCHAPI: thread dbWorker1 task mon_profile(5-557) shutting down
    18:41:53  SCHAPI: thread dbWorker2 task Low Memory Reconfig(50-556) shutting down
    18:41:54  SCHAPI: thread dbScheduler(43) shutting down
    18:42:04  Shutdown Mode
    18:42:06  Quiescent Mode
    18:42:06  Checkpoint Completed:  duration was 0 seconds.
    18:42:06  Wed May 20 - loguniq 75, logpos 0x2489018, timestamp: 0xdec8d3a Interval: 164

    18:42:06  Maximum server connections 2
    18:42:06  Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked 0, Plog used 1834, Llog used 18973

    <=!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! HERE !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
    18:42:07  IBM Informix Dynamic Server Stopped.   
    <=!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! HERE !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!

    ========================================================================
    Immediately starting:

    C:\Windows\system32>net start ixlur
    Starting service Informix IDS - ixlur.......
    Service Informix IDS - ixlur was successfully started.
    ========================================================================

    18:45:29  Parameter's user-configured value was adjusted. (DS_MAX_SCANS)
    18:45:29  Parameter's user-configured value was adjusted. (ONLIDX_MAXMEM)
    18:45:29  Parameter's user-configured value was adjusted. (MAX_PDQPRIORITY)
    18:45:29  IBM Informix Dynamic Server Started.
    18:45:29  Warning: The IBM IDS Innovator-C Edition license restriction limits
    18:45:29  the total shared memory size for this server to 8388608 KB.
    18:45:29  The maximum allowable shared memory was reset to this size to start the database server.
    18:45:29  Requested shared memory segment size rounded from 14208KB to 14848KB

    Wed May 20 18:45:29 2020

    18:45:29  Successfully added a bufferpool of page size 4K.

    18:45:29  Booting Language <c> from module <>
    18:45:29  Loading Module <CNULL>
    18:45:29  Booting Language <builtin> from module <>
    18:45:29  Loading Module <BUILTINNULL>
    18:45:35  DR: Cannot set the value of the onconfig parameter DRINTERVAL to 0.
                  This configuration parameter is not supported in IDS Innovator-C Edition.
    18:45:35  DR: Cannot set the value of the onconfig parameter DRLOSTFOUND to C:\PROGRA~1\IBMINF~1\etc\dr.lostfound.
                  This configuration parameter is not supported in IDS Innovator-C Edition.
    18:45:35  CCFLAGS2 value set to 0000000000000200
    18:45:35  SQL_FEAT_CTRL value set to 0000000000008008
    18:45:35  SQL_FEAT_CTRL2 value set to 0000000000000010
    18:45:35  SQL_DEF_CTRL value set to 00000000044004B0
    18:45:35  IBM Informix Dynamic Server Version 14.10.FC3IE
    18:45:36  Warning: stat() failed for chunk file C:\PROGRA~1\IBMINF~1\Storage\data1.000
    18:45:36  Warning: stat() failed for chunk file C:\PROGRA~1\IBMINF~1\Storage\blobdata1.000
    18:45:36  Warning: stat() failed for chunk file C:\PROGRA~1\IBMINF~1\Storage\dbsprilohy.000
    18:45:36  Warning: stat() failed for chunk file C:\PROGRA~1\IBMINF~1\storage\blobdata1.001
    18:45:36  Warning: stat() failed for chunk file C:\PROGRA~1\IBMINF~1\storage\blobdata1.002
    18:45:36  Warning: stat() failed for chunk file C:\PROGRA~1\IBMINF~1\storage\data1.001
    18:45:36  Warning: stat() failed for chunk file C:\PROGRA~1\IBMINF~1\storage\dbsprilohy.001
    18:45:36  Warning: stat() failed for chunk file C:\PROGRA~1\IBMINF~1\storage\data1.002
    18:45:36  Warning: stat() failed for chunk file C:\PROGRA~1\IBMINF~1\storage\dbsprilohy.002
    18:45:36  Warning: stat() failed for chunk file C:\PROGRA~1\IBMINF~1\storage\blobdata1.003
    18:45:36  IBM Informix Dynamic Server Initialized -- Shared Memory Initialized.

    18:45:36  Started 1 B-tree scanners.
    18:45:36  B-tree scanner threshold set at 5000.
    18:45:36  B-tree scanner range scan size set to -1.
    18:45:36  B-tree scanner ALICE mode set to 6.
    18:45:36  B-tree scanner index compression level set to med.
    <=!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! HERE !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
    18:45:36  Physical Recovery Started at Page (9:151611).
    18:45:36  Physical Recovery Complete: 20 Pages Examined, 20 Pages Restored.
    18:45:36  Logical Recovery Started.
    18:45:36  5 recovery worker threads will be started.
    18:45:39  Logical Recovery has reached the transaction cleanup phase.
    18:45:39  Logical Recovery Complete.
          0 Committed, 0 Rolled Back, 0 Open, 0 Bad Locks
    <=!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! HERE !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
    18:45:40  Dataskip is now OFF for all dbspaces
    18:45:40  CDR: Cannot set the value of the onconfig parameter CDR_SERIAL to 0.
                  This configuration parameter is not supported
                  in IDS Innovator-C Edition.
    18:45:40  Init operation complete - Mode Online
    18:45:40  Checkpoint Completed:  duration was 0 seconds.
    18:45:40  Wed May 20 - loguniq 75, logpos 0x248b0c0, timestamp: 0xdec8d3e Interval: 165

    18:45:40  Maximum server connections 0
    18:45:40  Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked 0, Plog used 28, Llog used 1

    18:45:40  On-Line Mode
    18:45:43  SCHAPI: Started dbScheduler thread.
    18:45:43  Booting Language <spl> from module <>
    18:45:43  Loading Module <SPLNULL>
    18:45:43  Auto Registration is synced
    18:45:43  SCHAPI: Started 2 dbWorker threads.
    18:45:45  Defragmenter cleaner thread now running
    18:45:45  Defragmenter cleaner thread cleaned:0 partitions

    Leos