We have a live and backup server config being updated with ai's every 5 mins. Twice in the last 3 weeks we have had a freeze on the backup database during an ai roll forward. I am unsure if this is a progress issue or os issue, but the log files on the server for the db and os show no error messages. The db log file just has a massive pause, 10.5 hours between the (1643) last opened message till the (1634) x notes were processed. Everything is fine afterwards during the ai catch up period. Anybody seen this before?
You are using an out of date browser. It may not display this or other websites correctly.
You should upgrade or use an alternative browser.
You should upgrade or use an alternative browser.
AI roll forward freeze?
- Thread starter tonysykes
- Start date
It has happened again here are the log files for veiwing, if anybody is veiwing this thread.
Wed Mar 30 21:41:19 2005
21:41:19 RFUTIL 0: rfutil -C roll forward session begin for root on batch. (451)
21:41:19 RFUTIL 0: Begin Physical Redo Phase at 32768 . (5326)
21:44:58 RFUTIL 0: Physical Redo Phase Completed at blk 77400 off 485 upd 24736. (7161)
21:44:58 RFUTIL 0: Beginning roll forward of after-image file /packtest/aivols/aivols/package.26228. (660)
21:44:58 RFUTIL 0: Last AIMAGE BEGIN Sat Dec 4 19:00:55 2004 (1640)
21:44:58 RFUTIL 0: Last AIMAGE NEW Wed Mar 30 21:35:11 2005 (1641)
21:44:58 RFUTIL 0: This is aimage file number 26228 since the last AIMAGE BEGIN. (1642)
21:44:58 RFUTIL 0: This file was last opened for output on Wed Mar 30 21:35:11 2005. (1643)
Thu Mar 31 08:00:48 2005
08:00:48 RFUTIL 0: 75054 notes were processed. (1634)
08:00:48 RFUTIL 0: 0 in-flight transactions. (3785)
08:00:48 RFUTIL 0: 3748 transactions were started
08:00:48 RFUTIL 0: 3748 transactions were ended
08:00:48 RFUTIL 0: At the end of the .ai file, 0 of them were still active
08:00:48 RFUTIL 0: Roll forward completed. (662)
08:00:49 RFUTIL 0: rfutil -C roll forward session end. (334)
Mon Apr 11 21:27:11 2005
21:27:11 RFUTIL 0: rfutil -C roll forward session begin for root on batch. (451)
21:27:12 RFUTIL 0: Begin Physical Redo Phase at 131072 . (5326)
21:30:51 RFUTIL 0: Physical Redo Phase Completed at blk 179809 off 1784 upd 25500. (7161)
21:30:52 RFUTIL 0: Beginning roll forward of after-image file /packtest/aivols/aivols/package.28798. (660)
21:30:52 RFUTIL 0: Last AIMAGE BEGIN Sat Dec 4 19:00:55 2004 (1640)
21:30:52 RFUTIL 0: Last AIMAGE NEW Mon Apr 11 21:10:11 2005 (1641)
21:30:52 RFUTIL 0: This is aimage file number 28798 since the last AIMAGE BEGIN. (1642)
21:30:52 RFUTIL 0: This file was last opened for output on Mon Apr 11 21:10:11 2005. (1643)
Tue Apr 12 08:00:13 2005
08:00:13 RFUTIL 0: 21339 notes were processed. (1634)
08:00:13 RFUTIL 0: 0 in-flight transactions. (3785)
08:00:13 RFUTIL 0: 1159 transactions were started
08:00:13 RFUTIL 0: 1158 transactions were ended
08:00:13 RFUTIL 0: At the end of the .ai file, 1 of them were still active
08:00:13 RFUTIL 0: Roll forward completed. (662)
08:00:13 RFUTIL 0: rfutil -C roll forward session end. (334)
Thu Apr 21 21:27:04 2005
21:27:04 RFUTIL 0: rfutil -C roll forward session begin for root on batch. (451)
21:27:04 RFUTIL 0: Begin Physical Redo Phase at 98304 . (5326)
21:30:32 RFUTIL 0: Physical Redo Phase Completed at blk 110042 off 3270 upd 64844. (7161)
21:30:33 RFUTIL 0: Beginning roll forward of after-image file /packtest/aivols/aivols/package.31229. (660)
21:30:33 RFUTIL 0: Last AIMAGE BEGIN Sat Dec 4 19:00:55 2004 (1640)
21:30:33 RFUTIL 0: Last AIMAGE NEW Thu Apr 21 21:10:10 2005 (1641)
21:30:33 RFUTIL 0: This is aimage file number 31229 since the last AIMAGE BEGIN. (1642)
21:30:33 RFUTIL 0: This file was last opened for output on Thu Apr 21 21:10:10 2005. (1643)
Fri Apr 22 08:00:29 2005
08:00:29 RFUTIL 0: 61248 notes were processed. (1634)
08:00:29 RFUTIL 0: 0 in-flight transactions. (3785)
08:00:29 RFUTIL 0: 3140 transactions were started
08:00:29 RFUTIL 0: 3139 transactions were ended
08:00:29 RFUTIL 0: At the end of the .ai file, 1 of them were still active
08:00:29 RFUTIL 0: Roll forward completed. (662)
08:00:30 RFUTIL 0: rfutil -C roll forward session end. (334)
There is nothing on this server which starts at either 21:30 or 08:00.
Wed Mar 30 21:41:19 2005
21:41:19 RFUTIL 0: rfutil -C roll forward session begin for root on batch. (451)
21:41:19 RFUTIL 0: Begin Physical Redo Phase at 32768 . (5326)
21:44:58 RFUTIL 0: Physical Redo Phase Completed at blk 77400 off 485 upd 24736. (7161)
21:44:58 RFUTIL 0: Beginning roll forward of after-image file /packtest/aivols/aivols/package.26228. (660)
21:44:58 RFUTIL 0: Last AIMAGE BEGIN Sat Dec 4 19:00:55 2004 (1640)
21:44:58 RFUTIL 0: Last AIMAGE NEW Wed Mar 30 21:35:11 2005 (1641)
21:44:58 RFUTIL 0: This is aimage file number 26228 since the last AIMAGE BEGIN. (1642)
21:44:58 RFUTIL 0: This file was last opened for output on Wed Mar 30 21:35:11 2005. (1643)
Thu Mar 31 08:00:48 2005
08:00:48 RFUTIL 0: 75054 notes were processed. (1634)
08:00:48 RFUTIL 0: 0 in-flight transactions. (3785)
08:00:48 RFUTIL 0: 3748 transactions were started
08:00:48 RFUTIL 0: 3748 transactions were ended
08:00:48 RFUTIL 0: At the end of the .ai file, 0 of them were still active
08:00:48 RFUTIL 0: Roll forward completed. (662)
08:00:49 RFUTIL 0: rfutil -C roll forward session end. (334)
Mon Apr 11 21:27:11 2005
21:27:11 RFUTIL 0: rfutil -C roll forward session begin for root on batch. (451)
21:27:12 RFUTIL 0: Begin Physical Redo Phase at 131072 . (5326)
21:30:51 RFUTIL 0: Physical Redo Phase Completed at blk 179809 off 1784 upd 25500. (7161)
21:30:52 RFUTIL 0: Beginning roll forward of after-image file /packtest/aivols/aivols/package.28798. (660)
21:30:52 RFUTIL 0: Last AIMAGE BEGIN Sat Dec 4 19:00:55 2004 (1640)
21:30:52 RFUTIL 0: Last AIMAGE NEW Mon Apr 11 21:10:11 2005 (1641)
21:30:52 RFUTIL 0: This is aimage file number 28798 since the last AIMAGE BEGIN. (1642)
21:30:52 RFUTIL 0: This file was last opened for output on Mon Apr 11 21:10:11 2005. (1643)
Tue Apr 12 08:00:13 2005
08:00:13 RFUTIL 0: 21339 notes were processed. (1634)
08:00:13 RFUTIL 0: 0 in-flight transactions. (3785)
08:00:13 RFUTIL 0: 1159 transactions were started
08:00:13 RFUTIL 0: 1158 transactions were ended
08:00:13 RFUTIL 0: At the end of the .ai file, 1 of them were still active
08:00:13 RFUTIL 0: Roll forward completed. (662)
08:00:13 RFUTIL 0: rfutil -C roll forward session end. (334)
Thu Apr 21 21:27:04 2005
21:27:04 RFUTIL 0: rfutil -C roll forward session begin for root on batch. (451)
21:27:04 RFUTIL 0: Begin Physical Redo Phase at 98304 . (5326)
21:30:32 RFUTIL 0: Physical Redo Phase Completed at blk 110042 off 3270 upd 64844. (7161)
21:30:33 RFUTIL 0: Beginning roll forward of after-image file /packtest/aivols/aivols/package.31229. (660)
21:30:33 RFUTIL 0: Last AIMAGE BEGIN Sat Dec 4 19:00:55 2004 (1640)
21:30:33 RFUTIL 0: Last AIMAGE NEW Thu Apr 21 21:10:10 2005 (1641)
21:30:33 RFUTIL 0: This is aimage file number 31229 since the last AIMAGE BEGIN. (1642)
21:30:33 RFUTIL 0: This file was last opened for output on Thu Apr 21 21:10:10 2005. (1643)
Fri Apr 22 08:00:29 2005
08:00:29 RFUTIL 0: 61248 notes were processed. (1634)
08:00:29 RFUTIL 0: 0 in-flight transactions. (3785)
08:00:29 RFUTIL 0: 3140 transactions were started
08:00:29 RFUTIL 0: 3139 transactions were ended
08:00:29 RFUTIL 0: At the end of the .ai file, 1 of them were still active
08:00:29 RFUTIL 0: Roll forward completed. (662)
08:00:30 RFUTIL 0: rfutil -C roll forward session end. (334)
There is nothing on this server which starts at either 21:30 or 08:00.
Simon Gaarthuis
New Member
Maybe the system is swapping out from memmory to disk and causes the system to be slow. Can you tell how many memmory is installed and how many is used?
A little background on the system, it has 8gb of memory and was going to be a live server, but was decided not to move the current live server, and leave this as a backup with a test system. So it is hardly used at all, so the memory would be minimal. The disks are on 2 raid controllers which are raid 10. If memory serves me correctly (the machine is a long way away from me) there are 24 drives. Its running unixware 7.1.3. Progress 9.1d09. And it happened again on Tuesday night.