[20200818]12c 10046跟踪时间戳2.txt

[20200818]12c 10046跟踪时间戳2.txt --//昨天测试12c 10046跟踪时间戳与原来11g不同,以前这里记录的从1970/1/1 UTC 的微秒数,而现在明显偏小. --//晚上验证看看这个偏移量来自那里. 1.环境: SCOTT@test01p> @ ver1 PORT_STRING                    VERSION        BANNER                                                                               CON_ID ------------------------------ -------------- -------------------------------------------------------------------------------- ---------- IBMPC/WIN_NT64-9.1.0           12.2.0.1.0     Oracle Database 12c Enterprise Edition Release 12.2.0.1.0 - 64bit Production              0 2.建立测试脚本并执行: $ cat ba.sql @ 10046on 12 select systimestamp from dual ; @ 10046off SCOTT@test01p> @ ba.sql Session altered. SYSTIMESTAMP -------------------------- 2020-08-18 20:56:49.472000 Session altered. 3.检查跟踪文件内容: ===================== PARSING IN CURSOR #792350760 len=30 dep=0 uid=81 oct=3 lid=81 tim=1271948665 hv=2569258288 ad='7ff11d1dd90' sqlid='8hwwkpuck7j9h' select systimestamp from dual END OF STMT PARSE #792350760:c=62400,e=91121,p=0,cr=236,cu=0,mis=1,r=0,dep=0,og=1,plh=1388734953,tim=1271948664 EXEC #792350760:c=0,e=34,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=1388734953,tim=1271948872 WAIT #792350760: nam='SQL*Net message to client' ela= 2 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=1271948959 FETCH #792350760:c=0,e=19,p=0,cr=0,cu=0,mis=0,r=1,dep=0,og=1,plh=1388734953,tim=1271949095 STAT #792350760 id=1 cnt=1 pid=0 pos=1 obj=0 op='FAST DUAL  (cr=0 pr=0 pw=0 str=1 time=3 us cost=2 size=0 card=1)' WAIT #792350760: nam='SQL*Net message from client' ela= 15311 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=1271964570 FETCH #792350760:c=0,e=2,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=1388734953,tim=1271964708 ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ WAIT #792350760: nam='SQL*Net message to client' ela= 1 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=1271964755 WAIT #792350760: nam='SQL*Net message from client' ela= 14640 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=1271979428 CLOSE #792350760:c=0,e=11,dep=0,type=0,tim=1271979539 ===================== $ ./xdate.sh 1271964708 1970-01-01 08:21:11.964708000 $ date -d "2020-08-18 20:56:49.472000 -1271.964708 seconds" +"%Y-%m-%d %T.%N" 2020-08-18 20:35:37.507292000 --//偏移量是2020-08-18 20:35:37.507292000. --//我检查oracle v$database,v$instance,v$thread视图里面有关时间的信息,根本对不上,无论从cdb还是pdb看,看到的时间都要晚. --//我重复执行脚本多次. SCOTT@test01p> @ ba Session altered. SYSTIMESTAMP -------------------------- 2020-08-18 21:14:32.191000 Session altered. --//跟踪文件内容: ===================== PARSING IN CURSOR #615598984 len=30 dep=0 uid=81 oct=3 lid=81 tim=2334648609 hv=2569258288 ad='7ff006d2ef8' sqlid='8hwwkpuck7j9h' select systimestamp from dual END OF STMT PARSE #615598984:c=62401,e=60225,p=0,cr=236,cu=0,mis=1,r=0,dep=0,og=1,plh=1388734953,tim=2334648607 EXEC #615598984:c=0,e=25,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=1388734953,tim=2334648819 WAIT #615598984: nam='SQL*Net message to client' ela= 2 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=2334648896 FETCH #615598984:c=0,e=15,p=0,cr=0,cu=0,mis=0,r=1,dep=0,og=1,plh=1388734953,tim=2334648956 STAT #615598984 id=1 cnt=1 pid=0 pos=1 obj=0 op='FAST DUAL  (cr=0 pr=0 pw=0 str=1 time=2 us cost=2 size=0 card=1)' WAIT #615598984: nam='SQL*Net message from client' ela= 550 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=2334649650 FETCH #615598984:c=0,e=2,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=1388734953,tim=2334649719 WAIT #615598984: nam='SQL*Net message to client' ela= 1 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=2334649755 WAIT #615598984: nam='SQL*Net message from client' ela= 1198 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=2334650984 ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ CLOSE #615598984:c=0,e=8,dep=0,type=0,tim=2334651068 ===================== $ date -d "2020-08-18 21:14:32.191000 -2334.650984 seconds" +"%Y-%m-%d %T.%N" 2020-08-18 20:35:37.540016000 --//基本偏移在2020-08-18 20:35:37. SYS@test> select * from v$instance   2  @ prxx ============================== INSTANCE_NUMBER               : 1 INSTANCE_NAME                 : test HOST_NAME                     : ZWS VERSION                       : 12.2.0.1.0 STARTUP_TIME                  : 2020-08-18 20:53:05 ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ STATUS                        : OPEN PARALLEL                      : NO THREAD#                       : 1 ARCHIVER                      : STARTED LOG_SWITCH_WAIT               : LOGINS                        : ALLOWED SHUTDOWN_PENDING              : NO DATABASE_STATUS               : ACTIVE INSTANCE_ROLE                 : PRIMARY_INSTANCE ACTIVE_STATE                  : NORMAL BLOCKED                       : NO CON_ID                        : 0 INSTANCE_MODE                 : REGULAR EDITION                       : EE FAMILY                        : DATABASE_TYPE                 : SINGLE PL/SQL procedure successfully completed. SYS@test> select * from v$thread   2  @ prxx ============================== THREAD#                       : 1 STATUS                        : OPEN ENABLED                       : PUBLIC GROUPS                        : 3 INSTANCE                      : test OPEN_TIME                     : 2020-08-18 20:53:38 ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ CURRENT_GROUP#                : 1 SEQUENCE#                     : 169 CHECKPOINT_CHANGE#            : 12268220 CHECKPOINT_TIME               : 2020-08-18 20:53:38 ENABLE_CHANGE#                : 1 ENABLE_TIME                   : 2018-10-06 21:16:41 DISABLE_CHANGE#               : 0 DISABLE_TIME                  : LAST_REDO_SEQUENCE#           : 169 LAST_REDO_BLOCK               : 119235 LAST_REDO_CHANGE#             : 12270513 LAST_REDO_TIME                : 2020-08-18 21:02:51 CON_ID                        : 0 PL/SQL procedure successfully completed. --//看了视乎windows系统这个偏差来源于,可以通过systeminfo启动观察. $ systeminfo | grep 2020 系统启动时间:     2020/8/18, 20:35:39 --//对比前面计算还是存在2秒的差值.真心不知道偏移量来之那里. --//注:在windows下执行通过管道报错. d:\> systeminfo | grep "2020" grep: writing output: Invalid argument 4.附上xdate脚本: $ cat xdate.sh #! /bin/bash #date -d "1970-01-01 00:00:00  UTC  $( echo "scale=6; $1/1000000"  |bc -l) seconds" +"%Y-%m-%d %T.%N" date -d "@$( echo "scale=6; $1/1000000"  |bc -l)" +"%Y-%m-%d %T.%N"