使用shell进行日志分析(r2第14天)

最近做数据批量加载的时候,是通过pl/sql嵌在shell脚本里执行的。 脚本运行后生成的日志类似如下的格式

Get Dump file for APP_TMP.TESTRESS_NAME_LINK...
Elapsed: 00:00:00.64
.
DB details is accessible from source schema ...
.
DB details is accessible from target schema ...
.
Directory  ext_datapump_dir has read,write permission ,proceed...
.
SYNONYM TESTEEMENT exists in CONNECT account,proceed...
.


Get Dump file for APP_TMP.TESTEEMENT...
Elapsed: 00:00:00.49
.
DB details is accessible from source schema ...
.
DB details is accessible from target schema ...
.
Directory  ext_datapump_dir has read,write permission ,proceed...
.
SYNONYM TESTEEMENT_RESOURCE exists in CONNECT account,proceed...
.

因为表比较多,所以日志看起来不是很清晰,想生成类似报表的格式来查看每个表耗费了多长时间,就一目了然了。

期望的结果类似下面的样子。

#########################################################################
Table_name                                          Elapsed        time  
#########################################################################
APP_TMP.TESTRESS_DATA...                            Elapsed: 00:00:01.13  
APP_TMP.TESTRESS_NAME_LINK...                       Elapsed: 00:00:00.64  
APP_TMP.TESTEEMENT...                               Elapsed: 00:00:00.49  
APP_TMP.TESTEEMENT_RESOURCE...                      Elapsed: 00:00:00.74  
APP_TMP.TEST_RES_HISTORY...                         Elapsed: 00:00:00.82  
APP_TMP.TEST_ACCOUNT...                             Elapsed: 00:00:01.03  
APP_TMP.TEST_ADDRESS_NAME...                        Elapsed: 00:00:00.78  
APP_TMP.TEST_AGED_TRIAL_BALANCE...                  Elapsed: 00:00:01.16  
APP_TMP.TEST_BILLING_ARRANGEMENT...                 Elapsed: 00:00:00.61  
APP_TMP.TEST_CHARGE_GROUP...                        Elapsed: 00:00:01.66  
APP_TMP.TEST_CHARGES...                             Elapsed: 00:00:06.73  
APP_TMP.TEST_CREDIT_DEBIT_LINK...                   Elapsed: 00:00:01.67  
APP_TMP.TEST_CUSTOMER_CREDIT...                     Elapsed: 00:00:00.40  
APP_TMP.TEST_DEPOSIT_REQUEST...                     Elapsed: 00:00:00.10  
APP_TMP.TEST_DIRECT_DEBIT_REQUEST...                Elapsed: 00:00:00.67  
APP_TMP.TEST_INVOICE...                             Elapsed: 00:00:01.98  
APP_TMP.TEST_PAY_CHANNEL...                         Elapsed: 00:00:00.53  
APP_TMP.TEST_PAYMENT...                             Elapsed: 00:00:01.28  
APP_TMP.TEST_PAYMENT_ACTIVITY...                    Elapsed: 00:00:00.19  


首先是根据关键字找到对应的行,下一行就是耗费的时间。想通过命令简单的实现。最后grep帮了大忙。
grep   -A1  --color=auto  "Get Dump file for "  extract.log
输出类似下面的样子。
--
Get Dump file for APP_TMP.TESTTOMER...
Elapsed: 00:00:00.91
--
Get Dump file for APP_TMP.TESTNT_DISTRIBUTE...
Elapsed: 00:00:00.84
--
Get Dump file for APP_TMP.TEST_MEMO...
Elapsed: 00:00:22.27
--
Get Dump file for APP_TMP.TESTE_DATA...
Elapsed: 00:00:01.55
--

达到了初步效果。就需要把冗余的信息去除“Get Dump file for ",然后能让对应的执行时间横向显示。
可以使用sed来做。
sed 's/Get Dump file for //' |sed 'N;N;s/\n/  /g'

APP_TMP.TESTRESS_DATA...  Elapsed: 00:00:01.13  --
APP_TMP.TESTRESS_NAME_LINK...  Elapsed: 00:00:00.64  --
APP_TMP.TESTEEMENT...  Elapsed: 00:00:00.49  --
APP_TMP.TESTEEMENT_RESOURCE...  Elapsed: 00:00:00.74  --

效果基本达到了,但是显示比较粗糙,不规整,这个时候awk能帮上大忙了。
使用如下的脚本来格式化输出
awk '
BEGIN{
print "#########################################################################"
printf "%-50s %8s %11s  \n", "Table_name","Elapsed","time"
print "#########################################################################"
}
{printf "%-50s %8s %11s  \n", $1,$2,$3,$4
}'


这样环环相扣,就可以输出基本完整的报告了。完整命令如下:
grep   -A1  --color=auto  "Get Dump file for "  extract.log |sed 's/Get Dump file for //' |sed 'N;N;s/\n/  /g' |awk '
BEGIN{
print "#########################################################################"
printf "%-50s %8s %11s  \n", "Table_name","Elapsed","time"
print "#########################################################################"
}
{printf "%-50s %8s %11s  \n", $1,$2,$3,$4
}'

输出:
#########################################################################
Table_name                                          Elapsed        time  
#########################################################################
APP_TMP.TESTRESS_DATA...                            Elapsed: 00:00:01.13  
APP_TMP.TESTRESS_NAME_LINK...                       Elapsed: 00:00:00.64  
APP_TMP.TESTEEMENT...                               Elapsed: 00:00:00.49 

原文发布于微信公众号 - 杨建荣的学习笔记(jianrong-notes)

原文发表时间:2014-06-25

本文参与腾讯云自媒体分享计划,欢迎正在阅读的你也加入,一起分享。

发表于

我来说两句

0 条评论
登录 后参与评论

相关文章

来自专栏杨建荣的学习笔记

11g升级性能问题之一 重建user_synonyms (笔记27天)

在测试环境11g升级之后,从测试那边反馈查询syn反应很慢。要持续差不多10分钟。其实这个syn中的数据只有200多条第一反应是cpu 100%了,查看果然是因...

3465
来自专栏deed博客

Oracle在Linux下安装

1842
来自专栏数据和云

极限优化:从75到2000,由技能到性能提升岂止80倍

崔华,网名 dbsnake Oracle ACE Director,ACOUG 核心专家 编辑手记:感谢崔华授权我们独家转载其精品文章,也欢迎大家向“Oracl...

2665
来自专栏乐沙弥的世界

Oracle ROWID

  ROWID 是一个类似于rownum的伪列,用于定位数据库中一条记录的一个相对唯一地址值。通常情况下,该值在该行数据插入到数据库表时即 被确定且唯一。而...

1354
来自专栏数据和云

补偏救弊 | 关于一致性读与语句性能关系的一大误区

作者简介 黄玮(Fuyuncat) 资深 Oracle DBA,致力于数据库底层技术的研究,其作品获得广大同行的高度评价。 个人网站 www.HelloDB...

2624
来自专栏乐沙弥的世界

Oracle ROWID 方式访问数据库

    和ROWNUM一样,ROWID是一个伪列,即是一个非用户定义的列,而又实际存储于数据库之中。每一个表都有一个ROWID列,一个ROWID值用于 唯一确定...

852
来自专栏杨建荣的学习笔记

关于等待事件"read by other session"(r3笔记第89天)

在查看数据库负载的时候,发现早上10点开始到12点的这两个钟头,系统负载异常的高。于是抓取了一个awr报告。 Snap IdSnap TimeSessions...

2909
来自专栏杨建荣的学习笔记

执行计划的偏差导致的性能问题(r3笔记第12天)

在生产环境中有一条sql语句,查看执行计划来看,效果还是可以接受的。 sql语句类似下面的样子,可以看到里面还使用了比较纠结的外连接。从执行计划来说,默认是走n...

2714
来自专栏杨建荣的学习笔记

ORACLE dataguard学习笔记 (91天)

今天在一台机器上模拟了dataguard,主备两个实例从物理上不共享任何归档文件路径。 主要有以下内容: dataguard Physical standby的...

29111
来自专栏数据库新发现

在Mac上通过Docker部署Oracle Database 12.2版本

Oracle 已经宣布支持了Docker部署,这也让我们在Mac上部署 Oracle 数据库有了多一个选择,这是我的第一个Docker应用,非常简便快速的就完...

1836

扫码关注云+社区