郁闷一年有余，请高手赐教

lmj702

DELL4600，SCO5。0。6，informix7。3
故障现象：备份时偶发性不能完成，备份进程无法结束。
分析：
A、备份程序为：开始事务，导表（fetch出来），最后将备份标志update一下。
B、经观察分析，备份进程长时间状态为（onstat分析）
250364 UPDATE         exch           CR  Wait 40    0    0    7.23   
说明：该备份程序只有一条update语句，同时update的表只有一条记录
C、根据session id号得知该进程在等待（onstat －g con）checkpoint的完成。
213      8201450c cp                 250447   22     
D、而checkpoint一直未完成。
不知原因为何，故障很偶然，故障时现场保留有onstat －a，ps －ef，netstat －a，如需其他资料请说明，请赐教，等待中。

songdu

online.log看看

AnEagle

备份前，有没有检查坏页

lmj702

先谢过各位。如何检查坏页？故障前10天刚做过数据库dbimport，online.log在单位，稍等

lmj702

15:00:22  Checkpoint Completed:  duration was 1 seconds.
15:05:37  Checkpoint Completed:  duration was 0 seconds.
15:10:51  Checkpoint Completed:  duration was 0 seconds.
15:16:06  Checkpoint Completed:  duration was 1 seconds.
15:21:23  Checkpoint Completed:  duration was 1 seconds.
15:26:55  Checkpoint Completed:  duration was 2 seconds.
15:32:14  Checkpoint Completed:  duration was 1 seconds.
15:37:22  Checkpoint Completed:  duration was 4 seconds.
15:42:49  Checkpoint Completed:  duration was 1 seconds.
15:48:13  Checkpoint Completed:  duration was 0 seconds.
15:53:49  Checkpoint Completed:  duration was 3 seconds.
15:59:03  Checkpoint Completed:  duration was 2 seconds.
16:04:14  Checkpoint Completed:  duration was 0 seconds.
16:09:42  Checkpoint Completed:  duration was 7 seconds.
16:14:42  Checkpoint Completed:  duration was 0 seconds.
16:20:06  Checkpoint Completed:  duration was 5 seconds.
16:25:34  Checkpoint Completed:  duration was 2 seconds.
16:33:47  Checkpoint Completed:  duration was 174 seconds.-----------------故障发生
16:33:49  Logical Log 7062 Complete.
16:33:50  Process exited with return code 139: /bin/sh /bin/sh -c /usr/informix/etc/log_full.sh 2 23 "Logical Log 7062 Complete." "Logical Log 7062 Complete."
16:33:58  Logical Log 7063 Complete.
16:34:01  Process exited with return code 139: /bin/sh /bin/sh -c /usr/informix/etc/log_full.sh 2 23 "Logical Log 7063 Complete." "Logical Log 7063 Complete."
16:34:12  Logical Log 7064 Complete.
16:34:14  Process exited with return code 139: /bin/sh /bin/sh -c /usr/informix/etc/log_full.sh 2 23 "Logical Log 7064 Complete." "Logical Log 7064 Complete."
16:50:52  Informix Dynamic Server Stopped.
16:53:59  Requested shared memory segment size rounded from 8000KB to 8192KB

Thu Nov 25 16:54:00 2004

16:54:00  dynamically allocated new shared memory segment (size 33554432)

16:54:00  Event alarms enabled.  ALARMPROG = '/usr/informix/etc/log_full.sh'
16:54:06  DR: DRAUTO is 0 (Off)
16:54:06  Requested shared memory segment size rounded from 588KB to 4096KB
16:54:06  Informix Dynamic Server Version 7.30.UC2   Software Serial Number AAC#R522009
16:54:07  Informix Dynamic Server Initialized -- Shared Memory Initialized.
16:54:07  Physical Recovery Started.
16:54:25  Physical Recovery Complete: 20945 Pages Restored.
16:54:25  Logical Recovery Started.
16:54:25  dynamically allocated new shared memory segment (size 33554432)

16:58:10  Logical Recovery Complete.
        0 Committed, 1 Rolled Back, 0 Open, 0 Bad Locks

16:58:10  Dataskip is now OFF for all dbspaces
16:58:11  On-Line Mode
16:58:11  Affinitied VP 3 to phys proc 1
16:58:11  Affinitied VP 1 to phys proc 0
16:58:19  Checkpoint Completed:  duration was 8 seconds.
16:59:06  Logical Log 7066 Complete.
16:59:10  Logical Log 7067 Complete.
16:59:11  Process exited with return code 139: /bin/sh /bin/sh -c /usr/informix/etc/log_full.sh 2 23 "Logical Log 7066 Complete." "Logical Log 7066 Complete."
16:59:12  Process exited with return code 139: /bin/sh /bin/sh -c /usr/informix/etc/log_full.sh 2 23 "Logical Log 7067 Complete." "Logical Log 7067 Complete."
16:59:21  Logical Log 7068 Complete.
16:59:22  Process exited with return code 139: /bin/sh /bin/sh -c /usr/informix/etc/log_full.sh 2 23 "Logical Log 7068 Complete." "Logical Log 7068 Complete."
16:59:43  Logical Log 7069 Complete.
16:59:45  Process exited with return code 139: /bin/sh /bin/sh -c /usr/informix/etc/log_full.sh 2 23 "Logical Log 7069 Complete." "Logical Log 7069 Complete."
17:04:21  Checkpoint Completed:  duration was 58 seconds.
17:39:58  Checkpoint Completed:  duration was 5 seconds.
17:41:24  Informix Dynamic Server Stopped.
17:41:37  Requested shared memory segment size rounded from 8000KB to 8192KB

Thu Nov 25 17:41:38 2004

17:41:38  dynamically allocated new shared memory segment (size 33554432)

17:41:38  Event alarms enabled.  ALARMPROG = '/usr/informix/etc/log_full.sh'
17:41:44  DR: DRAUTO is 0 (Off)
17:41:44  Requested shared memory segment size rounded from 588KB to 4096KB
17:41:44  Informix Dynamic Server Version 7.30.UC2   Software Serial Number AAC#R522009
17:41:45  Informix Dynamic Server Initialized -- Shared Memory Initialized.
17:41:45  Physical Recovery Started.
17:41:45  Physical Recovery Complete: 0 Pages Restored.
17:41:45  Logical Recovery Started.
17:41:45  dynamically allocated new shared memory segment (size 33554432)

17:41:50  Logical Recovery Complete.
        0 Committed, 0 Rolled Back, 0 Open, 0 Bad Locks

17:41:50  Dataskip is now OFF for all dbspaces
17:41:50  On-Line Mode
17:41:51  Affinitied VP 1 to phys proc 0
17:41:51  Affinitied VP 3 to phys proc 1
17:41:51  Checkpoint Completed:  duration was 0 seconds.
17:46:54  Checkpoint Completed:  duration was 0 seconds.
17:47:15  Logical Log 7061 - Backup Started
17:47:21  Logical Log 7061 - Backup Completed
17:47:21  Logical Log 7062 - Backup Started
17:47:27  Logical Log 7062 - Backup Completed
17:47:27  Logical Log 7063 - Backup Started
17:47:34  Logical Log 7063 - Backup Completed
17:47:34  Logical Log 7064 - Backup Started
17:47:42  Logical Log 7064 - Backup Completed
17:47:42  Logical Log 7065 - Backup Started
17:47:49  Logical Log 7065 - Backup Completed
17:47:49  Logical Log 7066 - Backup Started
17:47:57  Logical Log 7066 - Backup Completed
17:47:57  Logical Log 7067 - Backup Started
17:48:03  Logical Log 7067 - Backup Completed
17:48:03  Logical Log 7068 - Backup Started
17:48:13  Logical Log 7068 - Backup Completed
17:48:13  Logical Log 7069 - Backup Started
17:48:19  Logical Log 7069 - Backup Completed
17:48:19  Logical Log 7070 - Backup Started
17:48:20  Logical Log 7070 Complete.
17:48:21  Process exited with return code 139: /bin/sh /bin/sh -c /usr/informix/etc/log_full.sh 2 23 "Logical Log 7070 Complete." "Logical Log 7070 Complete."
17:48:24  Logical Log 7070 - Backup Completed
17:48:42  Logical Log 7071 - Backup Started
17:48:42  Logical Log 7071 - Backup Completed
17:48:43  Logical Log 7071 Complete.
17:48:43  Logical Log 7072 - Backup Started
17:48:43  Logical Log 7072 - Backup Completed
17:48:44  Logical Log 7072 Complete.
17:48:44  Logical Log 7073 - Backup Started
17:48:44  Process exited with return code 139: /bin/sh /bin/sh -c /usr/informix/etc/log_full.sh 2 23 "Logical Log 7071 Complete." "Logical Log 7071 Complete."
17:48:44  Logical Log 7073 - Backup Completed
17:48:45  Logical Log 7073 Complete.
17:48:45  Logical Log 7074 - Backup Started
17:48:45  Logical Log 7074 - Backup Completed
17:48:45  Process exited with return code 139: /bin/sh /bin/sh -c /usr/informix/etc/log_full.sh 2 23 "Logical Log 7072 Complete." "Logical Log 7072 Complete."
17:48:46  Logical Log 7074 Complete.
17:48:46  Process exited with return code 139: /bin/sh /bin/sh -c /usr/informix/etc/log_full.sh 2 23 "Logical Log 7073 Complete." "Logical Log 7073 Complete."
17:48:47  Process exited with return code 139: /bin/sh /bin/sh -c /usr/informix/etc/log_full.sh 2 23 "Logical Log 7074 Complete." "Logical Log 7074 Complete."
17:51:59  Checkpoint Completed:  duration was 0 seconds.
17:57:02  Checkpoint Completed:  duration was 0 seconds.
18:02:06  Checkpoint Completed:  duration was 0 seconds.
18:07:11  Checkpoint Completed:  duration was 0 seconds.
18:12:15  Checkpoint Completed:  duration was 0 seconds.
18:17:19  Checkpoint Completed:  duration was 0 seconds.
18:22:23  Checkpoint Completed:  duration was 0 seconds.
18:27:28  Checkpoint Completed:  duration was 0 seconds.
18:32:32  Checkpoint Completed:  duration was 0 seconds.
18:37:36  Checkpoint Completed:  duration was 0 seconds.
18:42:41  Checkpoint Completed:  duration was 0 seconds.
18:47:44  Checkpoint Completed:  duration was 0 seconds.
18:52:49  Checkpoint Completed:  duration was 0 seconds.
18:57:54  Checkpoint Completed:  duration was 0 seconds.
19:02:58  Checkpoint Completed:  duration was 0 seconds.
19:08:02  Checkpoint Completed:  duration was 0 seconds.
19:13:07  Checkpoint Completed:  duration was 0 seconds.
19:18:13  Checkpoint Completed:  duration was 0 seconds.
19:23:18  Checkpoint Completed:  duration was 0 seconds.
19:28:22  Checkpoint Completed:  duration was 0 seconds.
19:33:27  Checkpoint Completed:  duration was 0 seconds.
19:38:31  Checkpoint Completed:  duration was 0 seconds.
19:43:35  Checkpoint Completed:  duration was 0 seconds.

zoukunhong

逻辑日志满,增加逻辑日志 .

lmj702

不会吧，当时的状态
                                                                                                                                                                                                                                                                                                            
Physical Logging                                                                                                                                                                                                                                                                                            
Buffer bufused  bufsize  numpages numwrits pages/io                                                                                                                                                                                                                                                         
  P-2  0        8192     154011   1109     138.87%                                                                                                                                                                                                                                                         
      phybegin physize  phypos   phyused  %used                                                                                                                                                                                                                                                            
      10003f   50000    37156    20945    41.89                                                                                                                                                                                                                                                            
                                                                                                                                                                                                                                                                                                            
Logical Logging                                                                                                                                                                                                                                                                                             
Buffer bufused  bufsize  numrecs  numpages numwrits recs/pages pages/io                                                                                                                                                                                                                                    
  L-2  0        8192     5210626  349301   62944    14.9       5.5                                                                                                                                                                                                                                          
        Subsystem    numrecs  Log Space used                                                                                                                                                                                                                                                               
        OLDRSAM      5210626  633689020                                                                                                                                                                                                                                                                     
                                                                                                                                                                                                                                                                                                            
address  number   flags    uniqid   begin        size     used    %used                                                                                                                                                                                                                                    
887486e0 1        U------  7061     10c38f      15000    15000   100.00%                                                                                                                                                                                                                                    
887486fc 2        U-----L  7062     10fe27      15000    15000   100.00%                                                                                                                                                                                                                                    
88748718 3        U------  7063     1138bf      15000    15000   100.00%                                                                                                                                                                                                                                    
88748734 4        U------  7064     117357      15000    15000   100.00%                                                                                                                                                                                                                                    
88748750 5        U---C--  7065     11adef      15000    14978    99.85%                                                                                                                                                                                                                                    
8874876c 6        U-B----  7046     11e887      15000    15000   100.00%                                                                                                                                                                                                                                    
88748788 7        U-B----  7047     12231f      15000    15000   100.00%                                                                                                                                                                                                                                    
887487a4 8        U-B----  7048     125db7      15000    15000   100.00%                                                                                                                                                                                                                                    
887487c0 9        U-B----  7049     12984f      15000    15000   100.00%                                                                                                                                                                                                                                    
887487dc 10       U-B----  7050     12d2e7      15000    15000   100.00%                                                                                                                                                                                                                                    
887487f8 11       U-B----  7051     130d7f      15000     8299    55.33%                                                                                                                                                                                                                                    
88748814 12       U-B----  7052     134817      15000        9     0.06%                                                                                                                                                                                                                                    
88748830 13       U-B----  7053     1382af      15000        2     0.01%                                                                                                                                                                                                                                    
8874884c 14       U-B----  7054     13bd47      15000        2     0.01%                                                                                                                                                                                                                                    
88748868 15       U-B----  7055     13f7df      15000        2     0.01%                                                                                                                                                                                                                                    
88748884 16       U-B----  7056     143277      15000    11115    74.10%                                                                                                                                                                                                                                    
887488a0 17       U-B----  7057     146d0f      15000        8     0.05%                                                                                                                                                                                                                                    
887488bc 18       U-B----  7058     14a7a7      15000        3     0.02%                                                                                                                                                                                                                                    
887488d8 19       U-B----  7059     14e23f      15000        2     0.01%                                                                                                                                                                                                                                    
887488f4 20       U-B----  7060     151cd7      15000        2     0.01%

gkang

当时的 onstat 的 header  嗎?

lmj702

是但是onstat －l 的情况

gkang

7.3有 checkpoint 太長的問題, 看你的情況比較像 log full 的情況, 因為在第二次db server restart 的時候backup 十多個 log,