scheduler莫名的被kill -REASON="Job slave process was terminated"

saup007

早上来公司，看到8:01 的一个scheduler失败，但这个job执行有1分钟左右（run_duration为1分45秒），原因是「REASON="Job slave process was terminated"」

看alert并没有日志输出，看 /var/log/message

Oct 30 08:01:44 dbserver17 kernel: VM: killing process oracle

我在PL/SQL Developer手动run这个scheduler，还是报这个错。

/var/log/message 输出

Oct 30 10:23:36 dbserver17 kernel: VM: killing process oracle

我猜可能跟hugepage有关，被linux系统kill了，但确凿的证据没有找到。

$ free -m
             total       used       free     shared    buffers     cached
Mem:         96646      96406        239          0          4      27690
-/+ buffers/cache:      68711      27935
Swap:        32765       7966      24799

$ cat /proc/meminfo | grep -i hugepage
HugePages_Total: 32800
HugePages_Free:  10512
HugePages_Rsvd:   8702
Hugepagesize:     2048 kB

SQL> show parameter pga

NAME                                     TYPE         VALUE
------------------------------------ ----------- ------------------------------
pga_aggregate_target                     big integer 10G

SQL> show parameter sga

NAME                                     TYPE         VALUE
------------------------------------ ----------- ------------------------------
lock_sga                             boolean         FALSE
pre_page_sga                             boolean         FALSE
sga_max_size                             big integer 64G
sga_target                             big integer 64G

$ vmstat -SM 45 10
procs -----------memory---------- ---swap-- -----io---- --system-- -----cpu------
r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa st
0  5  10283    237      1  27336    0    0  1987   288    0    0  5  1 90  4  0
1  5  10064    240      0  27451    0    0 479494  4435 6527 24537  3  3 78 15  0
2  4   9904    244      1  27549    0    0 502464  5657 6457 22736  6  3 77 14  0
1  7   9635    239      1  27490    0    0 426233 12096 6015 22577  6  3 73 18  0
2  3   9610    238      0  27549    0    0 495628  6531 6012 24091  8  3 75 14  0
3  5   9585    243      0  27686    0    0 707705  5511 7331 28189  8  3 79 10  0
4  4   9472    245      1  27523    0    0 238116  5451 4093 14460  9  1 81  9  0
0  3   9448    236      1  27547    0    0 260717  5011 3566 14055  5  1 87  7  0

2  5   9473    236      1  27752    0    0 315135 12488 3855 15233  5  2 90  4  0
1  0   9760    274      1  27401    0    0 275383 13984 4244 14931  7  3 86  4  0


在数据库空闲的时候，我再次run这个scheduler，可以跑成功了。

求助怎么分析，能找到确切一些的原因并解决？

saup007

--从这里找到sql执行顺序和过程

select * from v$active_session_history where session_id=1119 order by to_char(sample_time,'yyyymmdd hh24:mi:ss') desc ;


17c1tm4udwh50  --> 8gbybvnypwftf  「这个sql_id只有4条记录，此时报错就是这条sql」

取出来单独执行，也报错了， 多次使用命令查看这个job执行时占了多少内存

     方法1：ps axu  | grep 16160 | grep -v grep | awk '{print $5,$6} --1位置虚拟内存占用，2位置实际物理内存占用

          21799244 654392

     方法2：top --> shift + M 按内存占用排序，RES为真实物理内存占用

第1次run job，报错了，但是才占用了330M内存(job run过程中多次执行最后一次有结果，因为被oom killer杀掉后，就没有这个进程了)，时间67s报错「由v$active_session_history得知」

     $ ps axu  | grep 26253 | grep -v grep | awk '{print $5,$6}'
       21637524 332456

第2次run job，成功了，但是最近占用将近1G内存，时间为172s，而且是成功的

     $ ps axu  | grep 26253 | grep -v grep | awk '{print $5,$6}'
       21799244 990376

那我们来看sql_id='8gbybvnypwftf'是什么，

单独手动执行一次，居然也报错了，时间很快，大概1s就报错了

再看执行计划，执行计划「采用并行了」

把涉及的表，degree从DEFAULT改为1

不知道小伙伴，还有其他想法和思路

Maclean Liu(刘相兵

给出alert.log 和当时的AWR

saup007

Maclean Liu(刘相兵 发表于 2014-10-31 16:04
给出alert.log 和当时的AWR

这个job是每天早上8：00开始。取awr，就是8:00--8:30。

saup007

把涉及的表degree由default改为1，今天早上8点job正常。看看明、后天情况。

saup007

之后没有报错了，但oom killer的机制在网上搜的资料还不能解答。

因为这个job所占用的内存还不是最大的，因为还有更大的，一个进程占10G的j001进程。

可能是内存使用增长速度过快，导致被oom killer杀掉了？