Number of logical logs growing ?
Posted in 2019
User reported logical logs automatically growing from 12 to 56+ on idle Informix 12.10.FC9IE instance despite DYNAMIC_LOGS set to 0. Investigation revealed AUTO_LLOG was enabled, causing logs to auto-extend during checkpoints triggered by crontab ontape backups. Unconfiguring AUTO_LLOG resolved the issue.
Auto-generated by DrWatson from the posts below — may be imperfect; read the full thread.
Topics: Backup & Restore, Storage & Space Management, Server Administration, Logging & Checkpoints
Hi all,
I'm doing some tests on ( new for me ) old 12.10.FC9IE
I have configured it on a small machine, and created a couple of small ( less
than 1G ) databases.
I've then moved logical log from rootdbs to a dedicated chunk, and so far so
good.
What I'm noticing is that the number of logical logs keeps growing also if the
machine ( and the databases ) are doing nothing.
I'll explain better: my instance is running on a machine to which I connect
only when I'm back from work, and baically I do not operate on the DB.
I've started the db with 12 logical logs, as I was used on my old 7.x DB, and
after some time I found ( as now for example ) that there are 56 logical logs.
No application is working on it, there are no application using the db and I
have also modified the onconfig file to have the DINAMYC_LOGS set to 0
The only operation to DB is a crontab that I used to have also on my old 7.x
DBs that, every 5 minutes issues an "ontape -a"
In my previous experience with IDS this was needed to avoid long transation
hanging and I have done the same here.
The only real difference is that on old IDS the logs were in rootdbs while
here I have dedicated a dbspace to them.
The Logical log on this IDS instance are quite empty:
...
...
...
47fd3f38 29 U-B---- 44704 3:42053 1500 19 1.27
47fe7fa8 30 U-B---- 44705 3:43553 1500 9 0.60
48021fb0 31 U-B---L 44706 3:45053 1500 7 0.47
47faafb0 32 U-B---- 44707 3:46553 1500 5 0.33
47fd3fa0 33 U-B---- 44708 3:48053 1500 5 0.33
477374c8 34 U-B---- 44709 3:49553 1500 98 6.53
...
...
...
Is there any way to avoid this logs automatically grow ( in number ) ?
I'm scared that they will, at a time, fill the dbspace and block some
transaction.
Thanks in advance
Pierluigi
Are there any messages on the online log indicating when the logical logs are
being added?
What is the output of:
onstat -g cfg DYNAMIC_LOGS
onstat -g cfg LTXHWM
onstat -g cfg LTXEHWM
And just to be sure, what is the result of the following query on the
sysmaster database:
select * from sysconfig where cf_name = 'DYNAMIC_LOGS';
I can't find any interesting info on logs, but decided to go in another way.
I've removed 40 logs, stopped the db, cleared the logfile and started again.
I'm now tracking when it will add a log ( in a script ) and tail the latest
lines of log file ( ol_informix1210.log ) t try to get a pattern.
Here the output you requested:
informix:~# onstat -g cfg DYNAMIC_LOGS
IBM Informix Dynamic Server Version 12.10.FC9IE -- On-Line -- Up 3 days
02:01:17 -- 185992 Kbytes
name current value
DYNAMIC_LOGS 0
informix:~# onstat -g cfg LTXHWM
IBM Informix Dynamic Server Version 12.10.FC9IE -- On-Line -- Up 3 days
02:01:29 -- 185992 Kbytes
name current value
LTXHWM 50
informix:~# onstat -g cfg LTXEHWM
IBM Informix Dynamic Server Version 12.10.FC9IE -- On-Line -- Up 3 days
02:01:34 -- 185992 Kbytes
name current value
LTXEHWM 60
informix:~# echo "database sysmaster; select * from sysconfig where cf_name =
'DYNAMIC_LOGS' " | dbaccess
Database selected.
cf_id 23
cf_name DYNAMIC_LOGS
cf_flags 163906
cf_original 0
cf_effective 0
cf_default 2
1 row(s) retrieved.
Database closed.
informix:~#
This is what I've found in logs at the time of crontab ontape -a jobs ( no one
was connected to the db, neither no jobs were usign it ):
17:20:01 Logical Log 47416 - Backup Started
17:20:01 Logical Log 47416 - Backup Completed
17:20:01 Logical Log 47417 - Backup Started
17:20:01 Logical Log 47417 - Backup Completed
17:20:01 Logical Log 47418 - Backup Started
17:20:01 Logical Log 47418 - Backup Completed
17:20:01 Logical Log 47419 - Backup Started
17:20:01 Logical Log 47419 - Backup Completed
17:20:01 Logical Log 47420 - Backup Started
17:20:01 Logical Log 47420 - Backup Completed
17:20:01 Performance Advisory: The logical log is running out of room during
checkpoint processing.
17:20:01 Results: Transactions are being blocked until the checkpoint is
complete.
17:20:01 Action: Increase the logical log space size.
17:20:01 Logical Log 47421 - Backup Started
17:20:01 Checkpoint Completed: duration was 0 seconds.
17:20:01 Wed Jun 12 - loguniq 47421, logpos 0x18, timestamp: 0xf964e40
Interval: 2404
17:20:01 Maximum server connections 1
17:20:01 Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked 1,
Plog used 1316, Llog used 3840
17:20:01 Logical Log 47421 - Backup Completed
17:20:01 Logical Log 47422 - Backup Started
17:20:01 Logical Log 47422 - Backup Completed
17:20:01 Logical Log 47418 Complete, timestamp: 0xf964e86.
17:20:01 Logical Log 47419 Complete, timestamp: 0xf964e86.
17:20:01 Logical Log 47420 Complete, timestamp: 0xf964e86.
17:20:01 Logical Log 47421 Complete, timestamp: 0xf964e86.
17:20:01 Logical Log 47422 Complete, timestamp: 0xf964e86.
17:20:01 Log file 13 added to DBspace 3.
17:20:01 Checkpoint Completed: duration was 0 seconds.
17:20:01 Wed Jun 12 - loguniq 47423, logpos 0xa400, timestamp: 0xf964ee3
Interval: 2405
17:20:01 Maximum server connections 1
17:20:01 Checkpoint Statistics - Avg. Txn Block Time 0.001, # Txns blocked 0,
Plog used 47, Llog used 22
17:20:01 ** AUTO TUNING - Logical Log extended.
Any idea ?
Well, something is causing activity in the instance and consuming logical logs. The timestamps and ordering of the online log seem strange. All those entries on the same second, the backup start entries before the corresponding logical log completing. Is the machine hibernating? Or aome task in the Informix internal scheduler? Maybe turning on SQLTRACE and check if it is capturing any activity? Activating the audit log could also give some information. The addition of logical logs is probably because you must have the parameter AUTO_LLOG activated. According to the online documentation, it is activated if we choose to initialize an instance during the Informix installation.
Hi louis, I0ve managed to unconfigure the AUTO_LLOG, and now my growing problem is no more present. Thanks a lot for that info, I wouldn't be able to find it !
Related threads
- Posting from the Informix-list
- Migrating from IDS 9.40.UC6 to 11.50.UC3
- Ip for a network session
- questions onstat -g