[20181213]ogg大量读取操作.txt

来源：这里教程网时间：2026-03-03 12:45:37 作者：

[20181213]ogg大量读取操作.txt --//我不知道是否异常,ogg存在大量读取操作. --//事情是这样的,dg磁盘空间爆满,解决磁盘空间不足的问题后再应用日志时,发现响应缓慢,基本无法操作服务器. --//当时想也许应用日志量太大,等待结束后也许问题消失. --//当日志应用结束后,我发现磁盘依旧存在大量读取操作,感觉很奇怪,这台机器内存充足. --//操作系统有文件系统缓存,不应该出现这么频繁的读取操作.于是开始着手分析看看. 1.使用iotop观察: # free total used free shared buffers cached Mem: 132061196 127204348 4856848 0 468756 44091004 -/+ buffers/cache: 82644588 49416608 Swap: 20972848 622000 20350848 --//虽然使用swap,但是看free还有将近5G内存呢.cached 将近43G呢.内存应该没有问题. # iotop -a Total DISK READ: 8.68 M/s | Total DISK WRITE: 472.90 K/s TID PRIO USER DISK READ DISK WRITE SWAPIN IO> COMMAND 16960 be/4 oracle 64.00 K 1654.34 M 10.70 % 13.49 % ora_dbw2_XXXXdg2 16956 be/4 oracle 36.00 K 1661.74 M 0.00 % 10.70 % ora_dbw0_XXXXdg2 16958 be/4 oracle 68.00 K 1732.70 M 0.00 % 10.24 % ora_dbw1_XXXXdg2 ... 719 be/4 oracle 2.67 G 0.00 B 0.00 % 0.49 % extract PARAMFILE /u01/ogg122/dirprm/EXTBA.prm REPORTFILE /u01/ogg122/dirrpt/EXTBA.rpt PROCESSID EXTBA USESUBDIRS 943 be/4 oracle 2.66 G 0.00 B 0.00 % 0.48 % extract PARAMFILE /u01/ogg122/dirprm/EXTZY.prm REPORTFILE /u01/ogg122/dirrpt/EXTZY.rpt PROCESSID EXTZY USESUBDIRS 926 be/4 oracle 2.66 G 0.00 B 0.00 % 0.48 % extract PARAMFILE /u01/ogg122/dirprm/EXTYB.prm REPORTFILE /u01/ogg122/dirrpt/EXTYB.rpt PROCESSID EXTYB USESUBDIRS 882 be/4 oracle 2.66 G 0.00 B 0.00 % 0.46 % extract PARAMFILE /u01/ogg122/dirprm/EXTOHS.prm REPORTFILE /u01/ogg122/dirrpt/EXTOHS.rpt PROCESSID EXTOHS USESUBDIRS 783 be/4 oracle 2.66 G 0.00 B 0.00 % 0.46 % extract PARAMFILE /u01/ogg122/dirprm/EXTGY.prm REPORTFILE /u01/ogg122/dirrpt/EXTGY.rpt PROCESSID EXTGY USESUBDIRS 838 be/4 oracle 2.67 G 0.00 B 0.00 % 0.46 % extract PARAMFILE /u01/ogg122/dirprm/EXTMS.prm REPORTFILE /u01/ogg122/dirrpt/EXTMS.rpt PROCESSID EXTMS USESUBDIRS 739 be/4 oracle 2.66 G 0.00 B 0.00 % 0.46 % extract PARAMFILE /u01/ogg122/dirprm/EXTCP.prm REPORTFILE /u01/ogg122/dirrpt/EXTCP.rpt PROCESSID EXTCP USESUBDIRS 805 be/4 oracle 2.66 G 0.00 B 0.00 % 0.46 % extract PARAMFILE /u01/ogg122/dirprm/EXTLIS.prm REPORTFILE /u01/ogg122/dirrpt/EXTLIS.rpt PROCESSID EXTLIS USESUBDIRS 761 be/4 oracle 2.66 G 0.00 B 0.00 % 0.42 % extract PARAMFILE /u01/ogg122/dirprm/EXTEMR.prm REPORTFILE /u01/ogg122/dirrpt/EXTEMR.rpt PROCESSID EXTEMR USESUBDIRS 17051 be/4 oracle 6.84 M 0.00 B 1.66 % 0.22 % ora_pr04_XXXXdg2 17036 be/4 oracle 0.00 B 0.00 B 0.50 % 0.19 % oracleXXXXdg2 (LOCAL=NO) 806 be/4 oracle 2.58 G 0.00 B 0.00 % 0.13 % extract PARAMFILE /u01/ogg122/dirprm/EXTLIS.prm REPORTFILE /u01/ogg122/dirrpt/EXTLIS.rpt PROCESSID EXTLIS USESUBDIRS 17024 be/4 oracle 49.39 M 432.71 M 0.00 % 0.12 % oracleXXXXdg2 (LOCAL=NO) 17169 be/4 oracle 0.00 B 0.00 B 0.72 % 0.12 % oracleXXXXdg2 (LOCAL=NO) 762 be/4 oracle 2.57 G 0.00 B 0.00 % 0.11 % extract PARAMFILE /u01/ogg122/dirprm/EXTEMR.prm REPORTFILE /u01/ogg122/dirrpt/EXTEMR.rpt PROCESSID EXTEMR USESUBDIRS 17094 be/4 oracle 0.00 B 5.00 M 0.65 % 0.09 % oracleXXXXdg2 (LOCAL=NO) 720 be/4 oracle 2.57 G 0.00 B 0.00 % 0.09 % extract PARAMFILE /u01/ogg122/dirprm/EXTBA.prm REPORTFILE /u01/ogg122/dirrpt/EXTBA.rpt PROCESSID EXTBA USESUBDIRS 740 be/4 oracle 2.58 G 0.00 B 0.00 % 0.09 % extract PARAMFILE /u01/ogg122/dirprm/EXTCP.prm REPORTFILE /u01/ogg122/dirrpt/EXTCP.rpt PROCESSID EXTCP USESUBDIRS 11068 be/4 root 4.96 M 0.00 B 0.00 % 0.09 % tmux 886 be/4 oracle 2.58 G 0.00 B 0.00 % 0.08 % extract PARAMFILE /u01/ogg122/dirprm/EXTOHS.prm REPORTFILE /u01/ogg122/dirrpt/EXTOHS.rpt PROCESSID EXTOHS USESUBDIRS 933 be/4 oracle 2.58 G 0.00 B 0.00 % 0.08 % extract PARAMFILE /u01/ogg122/dirprm/EXTYB.prm REPORTFILE /u01/ogg122/dirrpt/EXTYB.rpt PROCESSID EXTYB USESUBDIRS 38 rt/3 root 0.00 B 0.00 B 0.00 % 0.08 % [migration/12] 949 be/4 oracle 2.57 G 0.00 B 0.00 % 0.08 % extract PARAMFILE /u01/ogg122/dirprm/EXTZY.prm REPORTFILE /u01/ogg122/dirrpt/EXTZY.rpt PROCESSID EXTZY USESUBDIRS 784 be/4 oracle 2.58 G 0.00 B 0.00 % 0.08 % extract PARAMFILE /u01/ogg122/dirprm/EXTGY.prm REPORTFILE /u01/ogg122/dirrpt/EXTGY.rpt PROCESSID EXTGY USESUBDIRS 840 be/4 oracle 2.57 G 0.00 B 0.00 % 0.08 % extract PARAMFILE /u01/ogg122/dirprm/EXTMS.prm REPORTFILE /u01/ogg122/dirrpt/EXTMS.rpt PROCESSID EXTMS USESUBDIRS --//发现读取操作主要集中在extrace操作上. --//使用iostat观察: # dstat -t -d -D total,cciss/c0d0p3,sda,sdb,sdc,sde,sde,sdf,sdg,sdh -----time----- -dsk/total--dsk/cciss/c---dsk/sda-----dsk/sdb-----dsk/sdc-----dsk/sde-----dsk/sde-----dsk/sdf-----dsk/sdg-----dsk/sdh-- date/time | read writ: read writ: read writ: read writ: read writ: read writ: read writ: read writ: read writ: read writ 13-12 15:57:59| 51M 880k: 25M 440k: 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 13-12 15:58:00|8064k 944k:4020k 472k: 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 :8192B 0 : 0 0 13-12 15:58:01| 12M 6440k:6264k 2004k: 0 0 : 0 0 : 0 512k: 0 0 : 0 0 : 0 0 : 0 180k: 0 4096B 13-12 15:58:02| 51M 5016k: 25M 1808k: 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 188k: 0 508k 13-12 15:58:03|8016k 1688k:4008k 816k: 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 28k: 0 0 13-12 15:58:04| 12M 5400k:6012k 1844k: 0 0 : 0 0 : 0 512k: 0 0 : 0 0 : 0 0 :8192B 292k: 0 0 13-12 15:58:05| 51M 5360k: 25M 1312k: 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 16k 396k: 0 512k 13-12 15:58:06|8040k 1144k:4008k 572k: 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 :8192B 0 : 0 0 13-12 15:58:07| 12M 4672k:6008k 1572k: 0 0 : 0 0 : 0 512k: 0 0 : 0 0 : 0 0 : 32k 88k: 0 0 13-12 15:58:08| 45M 6336k: 22M 1232k: 0 0 : 0 0 : 0 512k: 0 0 : 0 0 : 0 0 : 0 512k: 0 512k 13-12 15:58:09| 14M 1568k:7152k 756k: 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 13-12 15:58:10| 12M 3904k:6016k 1256k: 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 256k 13-12 15:58:11| 45M 6960k: 23M 1944k: 0 0 : 0 0 : 0 512k: 0 0 : 0 0 : 0 0 : 0 512k: 0 256k 13-12 15:58:12| 14M 1448k:7016k 724k: 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 13-12 15:58:13| 12M 3440k:6008k 1268k: 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 184k 13-12 15:58:14| 45M 7440k: 22M 1936k: 0 0 : 0 0 : 0 512k: 0 0 : 0 0 : 0 0 : 0 512k: 0 328k 13-12 15:58:15| 14M 1408k:7012k 704k: 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 13-12 15:58:16| 12M 3752k:6148k 1876k: 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 13-12 15:58:17| 37M 9216k: 19M 2628k: 0 0 : 0 0 : 0 512k: 0 0 : 0 0 : 0 0 : 0 512k: 0 512k 13-12 15:58:18| 22M 1296k: 11M 648k: 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 13-12 15:58:19| 12M 1724k:6004k 820k: 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 13-12 15:58:20| 37M 9212k: 19M 2496k: 0 0 : 0 0 : 0 512k: 0 0 : 0 0 : 0 0 : 0 512k: 0 512k 13-12 15:58:21| 22M 2032k: 11M 1016k: 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 13-12 15:58:22| 12M 3400k:6312k 1672k: 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 13-12 15:58:23| 37M 11M: 19M 2920k: 0 0 : 0 0 : 0 512k: 0 0 : 0 0 : 0 0 :8192B 788k: 0 1024k 13-12 15:58:24| 18M 768k:9008k 384k: 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 13-12 15:58:25| 16M 1952k:8004k 964k: 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 13-12 15:58:26| 37M 6500k: 19M 1452k: 0 0 : 0 0 : 0 512k: 0 0 : 0 0 : 0 0 : 0 264k: 0 512k 13-12 15:58:27| 18M 652k:9384k 324k: 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 13-12 15:58:28| 16M 2136k:8056k 1040k: 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 16k 28k: 0 0 13-12 15:58:29| 36M 8768k: 18M 2264k: 0 0 : 0 0 : 0 512k: 0 0 : 0 0 : 0 0 : 0 584k: 0 512k 13-12 15:58:30| 20M 1272k: 9.8M 636k: 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 :8192B 0 : 0 0 13-12 15:58:31| 16M 3160k:8092k 1568k: 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 13-12 15:58:32| 35M 9944k: 18M 2324k: 0 0 : 0 0 : 0 744k: 0 0 : 0 0 : 0 0 : 0 880k: 0 512k 13-12 15:58:33| 20M 1320k: 9.8M 632k: 0 0 : 0 0 : 0 28k: 0 0 : 0 0 : 0 0 : 0 0 : 0 0 13-12 15:58:34| 16M 1920k:8056k 960k: 0 0 : 0 0 : 16k 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 13-12 15:58:35| 35M 9808k: 18M 2996k: 0 0 : 0 0 : 0 320k: 0 0 : 0 0 : 0 0 : 0 512k: 0 512k 13-12 15:58:36| 16M 1096k:8032k 548k: 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 13-12 15:58:37| 20M 2840k: 9.8M 1408k: 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 13-12 15:58:38| 34M 6360k: 17M 1276k: 0 0 : 0 0 : 0 436k: 0 0 : 0 0 : 0 0 : 0 444k: 0 512k 13-12 15:58:39| 17M 1552k:8579k 776k: 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 :8192B 0 : 0 0 13-12 15:58:40| 20M 1984k: 9.8M 944k: 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 :8192B 48k: 0 0 13-12 15:58:41| 18M 8128k:9004k 2080k: 0 0 : 0 0 : 0 512k: 0 0 : 0 0 : 0 0 : 0 448k: 0 512k 13-12 15:58:42| 33M 1152k: 17M 576k: 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 0 0 : 24k 0 : 0 0 --//注:这个版本的dstat很奇怪,total的数量加倍,也许是bug. --//找一个进程观察,注意iotap看到是tid.线程号 # ps -eLfc | egrep "UI[D]|71[9]" UID PID PPID LWP NLWP CLS PRI STIME TTY TIME CMD oracle 703 2649 719 12 TS 24 Sep26 ? 00:05:04 /u01/ogg122/extract PARAMFILE /u01/ogg122/dirprm/EXTBA.prm REPORTFILE /u01/ogg122/dirrpt/EXTBA.rpt PROCESSID EXTBA USESUBDIRS --//真正的进程号703. # ps -eLfc | egrep "UI[D]|70[3]" UID PID PPID LWP NLWP CLS PRI STIME TTY TIME CMD oracle 703 2649 703 12 TS 24 Sep26 ? 00:06:56 /u01/ogg122/extract PARAMFILE /u01/ogg122/dirprm/EXTBA.prm REPORTFILE /u01/ogg122/dirrpt/EXTBA.rpt PROCESSID EXTBA USESUBDIRS oracle 703 2649 704 12 TS 24 Sep26 ? 00:02:47 /u01/ogg122/extract PARAMFILE /u01/ogg122/dirprm/EXTBA.prm REPORTFILE /u01/ogg122/dirrpt/EXTBA.rpt PROCESSID EXTBA USESUBDIRS oracle 703 2649 705 12 TS 24 Sep26 ? 00:03:59 /u01/ogg122/extract PARAMFILE /u01/ogg122/dirprm/EXTBA.prm REPORTFILE /u01/ogg122/dirrpt/EXTBA.rpt PROCESSID EXTBA USESUBDIRS oracle 703 2649 706 12 TS 21 Sep26 ? 00:00:02 /u01/ogg122/extract PARAMFILE /u01/ogg122/dirprm/EXTBA.prm REPORTFILE /u01/ogg122/dirrpt/EXTBA.rpt PROCESSID EXTBA USESUBDIRS oracle 703 2649 707 12 TS 24 Sep26 ? 00:00:00 /u01/ogg122/extract PARAMFILE /u01/ogg122/dirprm/EXTBA.prm REPORTFILE /u01/ogg122/dirrpt/EXTBA.rpt PROCESSID EXTBA USESUBDIRS oracle 703 2649 712 12 TS 20 Sep26 ? 00:00:00 /u01/ogg122/extract PARAMFILE /u01/ogg122/dirprm/EXTBA.prm REPORTFILE /u01/ogg122/dirrpt/EXTBA.rpt PROCESSID EXTBA USESUBDIRS oracle 703 2649 715 12 TS 24 Sep26 ? 00:00:09 /u01/ogg122/extract PARAMFILE /u01/ogg122/dirprm/EXTBA.prm REPORTFILE /u01/ogg122/dirrpt/EXTBA.rpt PROCESSID EXTBA USESUBDIRS oracle 703 2649 716 12 TS 23 Sep26 ? 03:28:06 /u01/ogg122/extract PARAMFILE /u01/ogg122/dirprm/EXTBA.prm REPORTFILE /u01/ogg122/dirrpt/EXTBA.rpt PROCESSID EXTBA USESUBDIRS oracle 703 2649 717 12 TS 23 Sep26 ? 01:32:04 /u01/ogg122/extract PARAMFILE /u01/ogg122/dirprm/EXTBA.prm REPORTFILE /u01/ogg122/dirrpt/EXTBA.rpt PROCESSID EXTBA USESUBDIRS oracle 703 2649 718 12 TS 21 Sep26 ? 00:00:01 /u01/ogg122/extract PARAMFILE /u01/ogg122/dirprm/EXTBA.prm REPORTFILE /u01/ogg122/dirrpt/EXTBA.rpt PROCESSID EXTBA USESUBDIRS oracle 703 2649 719 12 TS 24 Sep26 ? 00:05:04 /u01/ogg122/extract PARAMFILE /u01/ogg122/dirprm/EXTBA.prm REPORTFILE /u01/ogg122/dirrpt/EXTBA.rpt PROCESSID EXTBA USESUBDIRS oracle 703 2649 720 12 TS 24 Sep26 ? 00:04:31 /u01/ogg122/extract PARAMFILE /u01/ogg122/dirprm/EXTBA.prm REPORTFILE /u01/ogg122/dirrpt/EXTBA.rpt PROCESSID EXTBA USESUBDIRS --//对应12个线程. # strace -t -p 703 -f -e read Process 703 attached with 12 threads - interrupt to quit --//12线程. [pid 716] 16:04:03 read(18, "\0\350\0\0\6\0\0\0\0\0\6\1\"R\1\0\0\0\0\0\2\0\0\0\0\0\0\0\0\0\0\0"..., 32784) = 232 [pid 719] 16:04:03 read(24, "\1\"\0\0\316\236.\0\343\25\0\0\200\200\266\244zoA\6\372\22\5\1\4\0 =,\4\0\0"..., 1024000) = 1024000 [pid 716] 16:04:03 read(18, "\0\350\0\0\6\0\0\0\0\0\6\1\"R\1\0\0\0\0\0\2\0\0\0\0\0\0\0\0\0\0\0"..., 32784) = 232 [pid 719] 16:04:03 read(24, "\1\"\0\0\236\246.\0\337\25\0\0\340\200K9\30\0 \0\24\0\23\0l\0\334\17\"\0\0\0"..., 1024000) = 1024000 [pid 717] 16:04:04 read(22, "\0\350\0\0\6\0\0\0\0\0\6\1\"R\1\0\0\0\0\0\2\0\0\0\0\0\0\0\0\0\0\0"..., 32784) = 232 [pid 720] 16:04:04 read(25, "\1\"\0\0=S7\0\325\20\0\0\20\200\25\315`\0\0\0\4j\6\0\352Ig-\1\0+O"..., 1024000) = 1024000 [pid 717] 16:04:04 read(22, "\0\350\0\0\6\0\0\0\0\0\6\1\"R\1\0\0\0\0\0\2\0\0\0\0\0\0\0\0\0\0\0"..., 32784) = 232 [pid 720] 16:04:04 read(25, "\1\"\0\0\r[7\0\307\20\0\0\244\200\4\201top:1878px;font-"..., 1024000) = 1024000 [pid 716] 16:04:06 read(18, "\0\350\0\0\6\0\0\0\0\0\6\1\"R\1\0\0\0\0\0\2\0\0\0\0\0\0\0\0\0\0\0"..., 32784) = 232 [pid 719] 16:04:06 read(24, "\1\"\0\0\307\242.\0\343\25\0\0\200\2005\6jH\321\10\372\22\5\1\3\0\0\0,\3\0\0"..., 1024000) = 1024000 [pid 716] 16:04:06 read(18, "\0\350\0\0\6\0\0\0\0\0\6\1\"R\1\0\0\0\0\0\2\0\0\0\0\0\0\0\0\0\0\0"..., 32784) = 232 [pid 716] 16:04:06 read(18, "\0\350\0\0\6\0\0\0\0\0\6\1\"R\1\0\0\0\0\0\2\0\0\0\0\0\0\0\0\0\0\0"..., 32784) = 232 [pid 719] 16:04:06 read(24, "\1\"\0\0\227\252.\0\337\25\0\0X\200\313\304\6\0\312\v\1\2or\n\0\30\0\6\0\t\0"..., 1024000) = 1024000 [pid 717] 16:04:07 read(22, "\0\350\0\0\6\0\0\0\0\0\6\1\"R\1\0\0\0\0\0\2\0\0\0\0\0\0\0\0\0\0\0"..., 32784) = 232 [pid 720] 16:04:07 read(25, "\1\"\0\0TT7\0\325\20\0\0\20\200\312\204`\0\0\0\0042\6\0\314Kg-\1\0Nz"..., 1024000) = 1024000 [pid 717] 16:04:07 read(22, "\0\350\0\0\6\0\0\0\0\0\6\1\"R\1\0\0\0\0\0\2\0\0\0\0\0\0\0\0\0\0\0"..., 32784) = 232 [pid 720] 16:04:07 read(25, "\1\"\0\0$\\7\0\307\20\0\0\344\200U\216nt-family:\313\316\314\345;f"..., 1024000) = 1024000 [pid 716] 16:04:09 read(18, "\0\350\0\0\6\0\0\0\0\0\6\1\"R\1\0\0\0\0\0\2\0\0\0\0\0\0\0\0\0\0\0"..., 32784) = 232 [pid 719] 16:04:09 read(24, "\1\"\0\0\356\245.\0\343\25\0\0\20\200v5@\0\0\0\1\0\6\0\vMg-\1\0\33F"..., 1024000) = 1024000 [pid 716] 16:04:09 read(18, "\0\350\0\0\6\0\0\0\0\0\6\1\"R\1\0\0\0\0\0\2\0\0\0\0\0\0\0\0\0\0\0"..., 32784) = 232 [pid 716] 16:04:09 read(18, "\0\350\0\0\6\0\0\0\0\0\6\1\"R\1\0\0\0\0\0\2\0\0\0\0\0\0\0\0\0\0\0"..., 32784) = 232 [pid 716] 16:04:09 read(18, "\0\350\0\0\6\0\0\0\0\0\6\1\"R\1\0\0\0\0\0\2\0\0\0\0\0\0\0\0\0\0\0"..., 32784) = 232 [pid 719] 16:04:09 read(24, "\1\"\0\0\276\255.\0\337\25\0\0<\200\3027\0\0\261\240\377\177\0\0\32\0\4\0\0\0\0\0"..., 1024000) = 1024000 [pid 717] 16:04:10 read(22, "\0\350\0\0\6\0\0\0\0\0\6\1\"R\1\0\0\0\0\0\2\0\0\0\0\0\0\0\0\0\0\0"..., 32784) = 232 [pid 720] 16:04:10 read(25, "\1\"\0\0005U7\0\325\20\0\0\30\201\254\367YTExY3JsMS5jcmww"..., 1024000) = 1024000 [pid 717] 16:04:10 read(22, "\0\350\0\0\6\0\0\0\0\0\6\1\"R\1\0\0\0\0\0\2\0\0\0\0\0\0\0\0\0\0\0"..., 32784) = 232 [pid 717] 16:04:10 read(22, "\0\350\0\0\6\0\0\0\0\0\6\1\"R\1\0\0\0\0\0\2\0\0\0\0\0\0\0\0\0\0\0"..., 32784) = 232 [pid 720] 16:04:10 read(25, "\1\"\0\0\5]7\0\307\20\0\0000\200;r:#000200;\"><div "..., 1024000) = 1024000 --//开始以为使用pread函数,没想到使用read。 # ls -l /proc/719/fd/24 /proc/720/fd/25 lr-x------ 1 oracle oinstall 64 2018-12-13 16:06:59 /proc/719/fd/24 -> /u01/app/oracle/oradata/XXXXdg2/onlinelog/onlinelog/group_10.327.862659471 lr-x------ 1 oracle oinstall 64 2018-12-13 16:06:59 /proc/720/fd/25 -> /u01/app/oracle/oradata/XXXXdg2/onlinelog/onlinelog/group_15.322.862659525 SYS@XXXXdg2> select * from v$STAndby_log; GROUP# DBID THREAD# SEQUENCE# BYTES BLOCKSIZE USED ARC STATUS FIRST_CHANGE# FIRST_TIME NEXT_CHANGE# NEXT_TIME LAST_CHANGE# LAST_TIME ------ ---------- ------- --------- ----------- --------- ------------ --- ---------- ------------- ------------------- ------------ --------- ------------ ------------------- 9 UNASSIGNED 1 0 4294967296 512 0 NO UNASSIGNED 10 2417323702 1 5603 4294967296 512 1594668032 YES ACTIVE 26529592505 2018-12-13 12:04:43 26531584553 2018-12-13 16:07:13 11 UNASSIGNED 1 0 4294967296 512 0 NO UNASSIGNED 12 UNASSIGNED 1 0 4294967296 512 0 NO UNASSIGNED 13 UNASSIGNED 1 0 4294967296 512 0 NO UNASSIGNED 14 UNASSIGNED 2 0 4294967296 512 0 NO UNASSIGNED 15 2417323702 2 4309 4294967296 512 1874407936 YES ACTIVE 26524824015 2018-12-13 02:27:19 26531584555 2018-12-13 16:07:13 16 UNASSIGNED 2 0 4294967296 512 0 NO UNASSIGNED 17 UNASSIGNED 2 0 4294967296 512 0 NO UNASSIGNED 18 UNASSIGNED 2 0 4294967296 512 0 NO UNASSIGNED 10 rows selected. --//group#=10,15 正好是standby接收日志文件. # ps -efc | egrep "UI[D]|extrac[t]" UID PID PPID CLS PRI STIME TTY TIME CMD oracle 703 2649 TS 24 Sep26 ? 05:23:46 /u01/ogg122/extract PARAMFILE /u01/ogg122/dirprm/EXTBA.prm REPORTFILE /u01/ogg122/dirrpt/EXTBA.rpt PROCESSID EXTBA USESUBDIRS oracle 725 2649 TS 24 Sep26 ? 04:54:19 /u01/ogg122/extract PARAMFILE /u01/ogg122/dirprm/EXTCP.prm REPORTFILE /u01/ogg122/dirrpt/EXTCP.rpt PROCESSID EXTCP USESUBDIRS oracle 745 2649 TS 24 Sep26 ? 05:20:09 /u01/ogg122/extract PARAMFILE /u01/ogg122/dirprm/EXTEMR.prm REPORTFILE /u01/ogg122/dirrpt/EXTEMR.rpt PROCESSID EXTEMR USESUBDIRS oracle 764 2649 TS 24 Sep26 ? 04:52:00 /u01/ogg122/extract PARAMFILE /u01/ogg122/dirprm/EXTGY.prm REPORTFILE /u01/ogg122/dirrpt/EXTGY.rpt PROCESSID EXTGY USESUBDIRS oracle 789 2649 TS 24 Sep26 ? 04:52:29 /u01/ogg122/extract PARAMFILE /u01/ogg122/dirprm/EXTLIS.prm REPORTFILE /u01/ogg122/dirrpt/EXTLIS.rpt PROCESSID EXTLIS USESUBDIRS oracle 811 2649 TS 24 Sep26 ? 05:00:34 /u01/ogg122/extract PARAMFILE /u01/ogg122/dirprm/EXTMS.prm REPORTFILE /u01/ogg122/dirrpt/EXTMS.rpt PROCESSID EXTMS USESUBDIRS oracle 825 2649 TS 23 Sep26 ? 04:52:44 /u01/ogg122/extract PARAMFILE /u01/ogg122/dirprm/EXTOHS.prm REPORTFILE /u01/ogg122/dirrpt/EXTOHS.rpt PROCESSID EXTOHS USESUBDIRS oracle 848 2649 TS 24 Sep26 ? 04:53:34 /u01/ogg122/extract PARAMFILE /u01/ogg122/dirprm/EXTYB.prm REPORTFILE /u01/ogg122/dirrpt/EXTYB.rpt PROCESSID EXTYB USESUBDIRS oracle 859 2649 TS 24 Sep26 ? 05:18:11 /u01/ogg122/extract PARAMFILE /u01/ogg122/dirprm/EXTZY.prm REPORTFILE /u01/ogg122/dirrpt/EXTZY.rpt PROCESSID EXTZY USESUBDIRS oracle 5773 2649 TS 24 Aug10 ? 05:33:08 /u01/ogg122/extract PARAMFILE /u01/ogg122/dirprm/PUMEMR.prm REPORTFILE /u01/ogg122/dirrpt/PUMEMR.rpt PROCESSID PUMEMR USESUBDIRS oracle 29015 2649 TS 24 Aug09 ? 03:08:10 /u01/ogg122/extract PARAMFILE /u01/ogg122/dirprm/PUMBA.prm REPORTFILE /u01/ogg122/dirrpt/PUMBA.rpt PROCESSID PUMBA USESUBDIRS oracle 29030 2649 TS 24 Aug09 ? 03:09:20 /u01/ogg122/extract PARAMFILE /u01/ogg122/dirprm/PUMCP.prm REPORTFILE /u01/ogg122/dirrpt/PUMCP.rpt PROCESSID PUMCP USESUBDIRS oracle 29070 2649 TS 24 Aug09 ? 02:57:34 /u01/ogg122/extract PARAMFILE /u01/ogg122/dirprm/PUMGY.prm REPORTFILE /u01/ogg122/dirrpt/PUMGY.rpt PROCESSID PUMGY USESUBDIRS oracle 29114 2649 TS 24 Aug09 ? 03:53:25 /u01/ogg122/extract PARAMFILE /u01/ogg122/dirprm/PUMZY.prm REPORTFILE /u01/ogg122/dirrpt/PUMZY.rpt PROCESSID PUMZY USESUBDIRS oracle 29202 2649 TS 24 Aug09 ? 03:05:47 /u01/ogg122/extract PARAMFILE /u01/ogg122/dirprm/PUMLIS.prm REPORTFILE /u01/ogg122/dirrpt/PUMLIS.rpt PROCESSID PUMLIS USESUBDIRS oracle 29211 2649 TS 24 Aug09 ? 03:29:47 /u01/ogg122/extract PARAMFILE /u01/ogg122/dirprm/PUMMS.prm REPORTFILE /u01/ogg122/dirrpt/PUMMS.rpt PROCESSID PUMMS USESUBDIRS oracle 29222 2649 TS 24 Aug09 ? 03:05:49 /u01/ogg122/extract PARAMFILE /u01/ogg122/dirprm/PUMOHS.prm REPORTFILE /u01/ogg122/dirrpt/PUMOHS.rpt PROCESSID PUMOHS USESUBDIRS oracle 29230 2649 TS 24 Aug09 ? 03:19:53 /u01/ogg122/extract PARAMFILE /u01/ogg122/dirprm/PUMYB.prm REPORTFILE /u01/ogg122/dirrpt/PUMYB.rpt PROCESSID PUMYB USESUBDIRS --//一共18个extract进程.9个抽取,9个pump .其中抽取的进程都会大量的读取接收的日志. GGSCI (XXXXdg2) 3> info all Program Status Group Lag at Chkpt Time Since Chkpt MANAGER RUNNING EXTRACT RUNNING EXTBA 00:00:01 00:00:01 EXTRACT RUNNING EXTCP 00:00:00 00:00:00 EXTRACT RUNNING EXTEMR 00:00:03 00:00:01 EXTRACT RUNNING EXTGY 00:00:01 00:00:07 EXTRACT RUNNING EXTLIS 00:00:02 00:00:06 EXTRACT RUNNING EXTMS 00:00:01 00:00:01 EXTRACT RUNNING EXTOHS 00:00:02 00:00:04 EXTRACT RUNNING EXTYB 00:00:04 00:00:01 EXTRACT RUNNING EXTZY 00:00:03 00:00:01 EXTRACT RUNNING PUMBA 00:00:00 00:00:06 EXTRACT RUNNING PUMCP 00:00:00 00:00:06 EXTRACT RUNNING PUMEMR 00:00:00 00:00:03 EXTRACT RUNNING PUMGY 00:00:00 00:00:06 EXTRACT RUNNING PUMLIS 00:00:00 00:00:05 EXTRACT RUNNING PUMMS 00:00:00 00:00:03 EXTRACT RUNNING PUMOHS 00:00:00 00:00:06 EXTRACT RUNNING PUMYB 00:00:00 00:00:05 EXTRACT RUNNING PUMZY 00:00:00 00:00:03 --//9个抽取进程,9个pump进程. --//可以想像应该9个抽取进程都在读取standby日志文件(注2个实例的standby的日志). --//我在想如果是rac环境,ogg又是如何抽取呢? 这样的抽取方式对于磁盘可能存在更大的压力.看来要想办法看看dg的awr报表才行. --//先执行如下监测open那些文件句柄. # strace -p 745 -f -e open | tee /tmp/aa.txt --//...等 --//再主库做1个日志切换. SYS@XXXX1> alter system archive log current ; System altered. # strace -p 745 -f -e open | tee /tmp/aa.txt Process 745 attached with 12 threads - interrupt to quit [pid 759] open("/u01/app/oracle/oradata/XXXXdg2/onlinelog/onlinelog/group_14.323.862659519", O_RDONLY|O_DIRECT) = 23 [pid 758] open("/u01/app/oracle/oradata/XXXXdg2/onlinelog/onlinelog/group_10.327.862659471", O_RDONLY|O_DIRECT) = 25 --//注意看打开flag. # man open ... O_DIRECT Try to minimize cache effects of the I/O to and from this file. In general this will degrade performance, but it is useful in special situations, such as when applications do their own caching. File I/O is done directly to/from user space buffers. The I/O is synchronous, i.e., at the completion of a read(2) or write(2), data is guaranteed to have been transferred. Under Linux 2.4 transfer sizes, and the alignment of user buffer and file offset must all be multiples of the logical block size of the file system. Under Linux 2.6 alignment must fit the block size of the device. --//这样读取效率会低下,ogg这样用应该有它的道理,也许我不知道. --//参考链接:http://blog.itpub.net/267265/viewspace-2285296/ --//如果应用产生大量日志将会产生大量磁盘读取操作.抽取进程越多.读取日志量就会翻倍. --//不知道是否可以合并1个抽取进程,多个pump进程. --//自己还有1个疑问,如果在rac+asm的环境下,ogg抽取采用那种读取日志模式.没有环境,无法测试. --//我打开iotop接近1天: # iotop -a Total DISK READ: 8.68 M/s | Total DISK WRITE: 472.90 K/s TID PRIO USER DISK READ DISK WRITE SWAPIN IO> COMMAND ... 739 be/4 oracle 53.98 G 0.00 B 0.00 % 0.28 % extract PARAMFILE /u01/ogg122/dirprm/EXTCP.prm REPORTFILE /u01/ogg122/dirrpt/EXTCP.rpt PROCESSID EXTCP USESUBDIRS 805 be/4 oracle 53.96 G 0.00 B 0.00 % 0.28 % extract PARAMFILE /u01/ogg122/dirprm/EXTLIS.prm REPORTFILE /u01/ogg122/dirrpt/EXTLIS.rpt PROCESSID EXTLIS USESUBDIRS 882 be/4 oracle 53.98 G 0.00 B 0.00 % 0.28 % extract PARAMFILE /u01/ogg122/dirprm/EXTOHS.prm REPORTFILE /u01/ogg122/dirrpt/EXTOHS.rpt PROCESSID EXTOHS USESUBDIRS 926 be/4 oracle 54.03 G 0.00 B 0.00 % 0.28 % extract PARAMFILE /u01/ogg122/dirprm/EXTYB.prm REPORTFILE /u01/ogg122/dirrpt/EXTYB.rpt PROCESSID EXTYB USESUBDIRS 943 be/4 oracle 53.89 G 0.00 B 0.00 % 0.28 % extract PARAMFILE /u01/ogg122/dirprm/EXTZY.prm REPORTFILE /u01/ogg122/dirrpt/EXTZY.rpt PROCESSID EXTZY USESUBDIRS 719 be/4 oracle 54.00 G 0.00 B 0.00 % 0.28 % extract PARAMFILE /u01/ogg122/dirprm/EXTBA.prm REPORTFILE /u01/ogg122/dirrpt/EXTBA.rpt PROCESSID EXTBA USESUBDIRS 838 be/4 oracle 54.02 G 0.00 B 0.00 % 0.28 % extract PARAMFILE /u01/ogg122/dirprm/EXTMS.prm REPORTFILE /u01/ogg122/dirrpt/EXTMS.rpt PROCESSID EXTMS USESUBDIRS 761 be/4 oracle 54.05 G 0.00 B 0.00 % 0.28 % extract PARAMFILE /u01/ogg122/dirprm/EXTEMR.prm REPORTFILE /u01/ogg122/dirrpt/EXTEMR.rpt PROCESSID EXTEMR USESUBDIRS 783 be/4 oracle 53.95 G 0.00 B 0.00 % 0.27 % extract PARAMFILE /u01/ogg122/dirprm/EXTGY.prm REPORTFILE /u01/ogg122/dirrpt/EXTGY.rpt PROCESSID EXTGY USESUBDIRS ... 933 be/4 oracle 51.41 G 0.00 B 0.01 % 0.09 % extract PARAMFILE /u01/ogg122/dirprm/EXTYB.prm REPORTFILE /u01/ogg122/dirrpt/EXTYB.rpt PROCESSID EXTYB USESUBDIRS 784 be/4 oracle 51.43 G 0.00 B 0.01 % 0.09 % extract PARAMFILE /u01/ogg122/dirprm/EXTGY.prm REPORTFILE /u01/ogg122/dirrpt/EXTGY.rpt PROCESSID EXTGY USESUBDIRS 740 be/4 oracle 51.40 G 0.00 B 0.00 % 0.09 % extract PARAMFILE /u01/ogg122/dirprm/EXTCP.prm REPORTFILE /u01/ogg122/dirrpt/EXTCP.rpt PROCESSID EXTCP USESUBDIRS 840 be/4 oracle 51.35 G 0.00 B 0.01 % 0.09 % extract PARAMFILE /u01/ogg122/dirprm/EXTMS.prm REPORTFILE /u01/ogg122/dirrpt/EXTMS.rpt PROCESSID EXTMS USESUBDIRS 762 be/4 oracle 51.41 G 0.00 B 0.01 % 0.09 % extract PARAMFILE /u01/ogg122/dirprm/EXTEMR.prm REPORTFILE /u01/ogg122/dirrpt/EXTEMR.rpt PROCESSID EXTEMR USESUBDIRS 886 be/4 oracle 51.46 G 0.00 B 0.01 % 0.09 % extract PARAMFILE /u01/ogg122/dirprm/EXTOHS.prm REPORTFILE /u01/ogg122/dirrpt/EXTOHS.rpt PROCESSID EXTOHS USESUBDIRS 720 be/4 oracle 51.46 G 0.00 B 0.00 % 0.09 % extract PARAMFILE /u01/ogg122/dirprm/EXTBA.prm REPORTFILE /u01/ogg122/dirrpt/EXTBA.rpt PROCESSID EXTBA USESUBDIRS 806 be/4 oracle 51.48 G 0.00 B 0.02 % 0.09 % extract PARAMFILE /u01/ogg122/dirprm/EXTLIS.prm REPORTFILE /u01/ogg122/dirrpt/EXTLIS.rpt PROCESSID EXTLIS USESUBDIRS 949 be/4 oracle 51.49 G 0.00 B 0.01 % 0.09 % extract PARAMFILE /u01/ogg122/dirprm/EXTZY.prm REPORTFILE /u01/ogg122/dirrpt/EXTZY.rpt PROCESSID EXTZY USESUBDIRS --//将近5X G,9个抽取进程,实际上18个(分别从rac的2个实例读取日志).一天有将近18*51G = 918G读取操作. --//当然这点IO量对于现在的硬件根本不是问题. d:\tools\sql>d_arc DATE WEEK SIZE_MB NUMBER_OF_SWITCHES_PER_DAY ------------- ------------- ---------- -------------------------- 2018-12-14 50 FRIDAY 4201 4 2018-12-13 50 THURSDAY 10188 6 2018-12-12 50 WEDNESDAY 11645 7 2018-12-11 50 TUESDAY 4890 4 2018-12-10 50 MONDAY 4932 4 2018-12-09 49 SUNDAY 4864 4 2018-12-08 49 SATURDAY 6646 5 2018-12-07 49 FRIDAY 12147 7 2018-12-06 49 THURSDAY 11557 7 2018-12-05 49 WEDNESDAY 10086 6 2018-12-04 49 TUESDAY 12502 8 2018-12-03 49 MONDAY 11890 6 .... --//一般正常业务每天大约11G上下.12-10,12-11号这两天偏少,是因为我们这里放假. ^_^. --//我不熟悉ogg,也不知道我的分析是否正确,或者有什么方法规避这样的读取操作.或者什么参数调整规避打开使用O_DIRECT. --//在我看来抽取脚本XXX.prm,前面部分都以一样的,仅仅后面抽取的表不同.要没有别的方式可以采取1个抽取,1个pump或者拆分 --//多个pump方式(注我不知道是否可行,感觉应该是个可以),这样并不会执行缓慢.而且ogg抽取我们并没有实时性需求. --//我有点奇怪的是生产系统rac环境,2边日志生成量并不相同,正常在大约3:1之间.也就是实例1每天产生8G,实例2每天产生3G上下. --//而抽取进程读取两边实例日志的量确非常接近,都是5XG,这样一定存在重复读取的情况,也就是读取大量"垃圾"日志.看来还给做一些 --//细节分析. --//read函数里面并没有偏移参数设置,读取后自动移到下一个位置. --//对于ogg实在不熟悉,一些细节下个星期继续分析看看. --//附上d_arc.sql的脚本: $ cat d_arc.sql SELECT TO_CHAR (first_time, 'YYYY-MM-DD WW') AS "DATE" ,TO_CHAR (first_time, 'DAY') week ,ROUND (SUM ( (blocks + 1) * block_size) / 1024 / 1024, 0) AS "SIZE_MB" ,COUNT (*) AS "NUMBER_OF_SWITCHES_PER_DAY" FROM v$archived_log WHERE dest_id = 1 and first_time>=trunc(sysdate)-40 GROUP BY TO_CHAR (first_time, 'YYYY-MM-DD WW'), TO_CHAR (first_time, 'DAY') ORDER BY TO_CHAR (first_time, 'YYYY-MM-DD WW') DESC; quit