2017年3月2日星期四

GC日志分析

MinorGC

13165.625①: [GC (GCLocker Initiated GC)② 13165.625: [ParNew③: 77440K->6531K(77440K)④, 0.0064810 secs] 231539K->160787K(334612K)⑤, 0.0065377 secs] [Times: user=0.01 sys=0.01, real=0.00 secs]⑥
上面是一次普通的小型垃圾回收(MinorGC)的日志；
①  时间标记，GC开始的时间（距离进程启动），单位秒；
② GC的发生原因，最常见的是Allocation Failure 和 GC Locker；
GC Cause
Description
Allocation Failure
Application tried to make a new allocation and failed due to lack of available space in Young generation; hence Minor GC is required. On Linux, the JVM can trigger a GC if the kernel notifies there isn't much memory left via mem_notify.
程序试图在新生区创建对象时，出现空间不足从而导致创建失败；因此需要触发一个MinorGC；
GC Locker
GC is started after all threads leave the JNI Critical region. For more information on JNI, refer to the Java Native Interface documentation website. GC is blocked when any thread is in the JNI Critical region and can start only when all of them outside of it.
JNI的critical region会阻止GC的发生，这个机制会允许执行的线程执行完毕，由最终的release方法退出JNI的critical region；当有线程进入critical region时，此时发生了gc需求，系统会阻止其他线程进入并等待所有进入的线程退出，直到所有线程退出，会触发一次gc；
G1 Evacuation Pause
This is actual only for the G1 collector. It indicates that it is copying live objects from one set of regions (Young and sometimes Young + Tenured, which is called Mixed) to another set of regions.
G1 Humongous Allocation
This is actual only for the G1 collector. Humongous is an allocation when its size is greater than 50% of one region size; the object then allocated in special space. Nevertheless, it also causes normal GC collection to get more (possibly continuous also) space for such objects.
CMS Initial Mark
Initial mark phase of CMS, for more details, see Phases of CMS. It also triggers Young Space collection.
System.gc()
There was a System.gc() call in the application code. You can start JVM with the -XX:+DisableExplicitGC flag to disable such behavior.
Adaptive Size Ergonomics
Indicates you are using the adaptive heap size policy (ability to change Young and Tenured spaces size at runtime), enabled via the -XX:+UseAdaptiveSizePolicy flag. By default, it is enabled in the recent versions of JVM.
Allocation Profiler
This is actual only for versions of Java before 8 and only when  -Xaprof  is set. It triggers just before JVM exits.
Heap Inspection
GC was triggered by an inspection operation on the heap, most probably by the jmap tool with the -histo:live  flag set.
Heap Dump
GC was initiated before heap dump is made by some profiling instrument.
No GC
Normally, you shouldn't see this reason. It was occurring in older Java versions, in case jstat command was started before any collection occurred. Other case is when jstat checks GC without any GC activity.
Last Ditch Collection
When Metaspace (Java 8+) or PermGen (Java 7-) is full and you can't allocate a new object here, JVM first tries to clean it, triggering appropriate collector. If that's not possible, it then tries to expand it. If that doesn't work as well, it triggers Full GC with this cause name. Soft references are being cleaned during it as well.
Perm Generation Full
Triggered as a result of an allocation failure in PermGen. Actual for Java versions prior to 8.
Metadata GC Threshold
Triggered as a result of an allocation failure in Metaspace. Metaspace is a replacement for PermGen in Java 8+.
JvmtiEnv ForceGarbageCollection
Something called the JVM tool interface function ForceGarbageCollection.
③ ParNew是JVM中的一种垃圾回收器；它是Serial收集器的多线程版本；
④ 新生区回收前->回收后(总可用)的大小；
⑤ heap回收前->回收后(总可用)
⑥ 时间消耗情况，具体参考 下方Times说明

CMS fullGC日志

启用了CMS的一次fullGC日志；
13157.505: [GC (CMS Initial Mark) [1 CMS-initial-mark: 241153K(257172K)] 251001K(334612K), 0.0165025 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
13157.522: [CMS-concurrent-mark-start]
13158.764: [CMS-concurrent-mark: 1.243/1.243 secs] [Times: user=1.55 sys=0.80, real=1.25 secs]
13158.765: [CMS-concurrent-preclean-start]
13158.775: [CMS-concurrent-preclean: 0.010/0.011 secs] [Times: user=0.01 sys=0.01, real=0.01 secs]
13158.775: [CMS-concurrent-abortable-preclean-start]
 CMS: abort preclean due to time 13163.867: [CMS-concurrent-abortable-preclean: 4.677/5.092 secs] [Times: user=5.95 sys=1.03, real=5.09 secs]
13163.868: [GC (CMS Final Remark) [YG occupancy: 66334 K (77440 K)]13163.868: [Rescan (parallel) , 0.0552409 secs]13163.923: [weak refs processing, 0.0012519 secs]13163.924: [class unloading, 0.0099594 secs]13163.934: [scrub symbol table, 0.0051363 secs]13163.939: [scrub string ta
ble, 0.0014047 secs][1 CMS-remark: 241153K(257172K)] 307488K(334612K), 0.0740422 secs] [Times: user=0.14 sys=0.00, real=0.07 secs]
13163.945: [CMS-concurrent-sweep-start]
13164.065: [CMS-concurrent-sweep: 0.120/0.120 secs] [Times: user=0.12 sys=0.00, real=0.12 secs]
13164.065: [CMS-concurrent-reset-start]
13164.074: [CMS-concurrent-reset: 0.009/0.009 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]

关于CMS垃圾回收阶段说明

  • CMS Initial Mark：初始标记阶段，这个阶段标记由根可以直接到达的对象，该阶段会停止JVM的所有线程(STOP-THE-WORLD)；
  • CMS concurrent-mark：并发标记阶段，在第一个阶段被暂停的线程重新开始运行，由前阶段标记过的对象出发，所有可到达的对象都在本阶段中标记。本阶段不会影响对外服务；
  • CMS-concurrent-preclean：预清理阶段，在本阶段，会查找前一阶段执行过程中,从新生代晋升或新分配或被更新的对象。通过并发地重新扫描这些对象，预清理阶段可以减少下一个stop-the-world 重新标记阶段的工作量。
  • CMS Final Remark(Rescan)：该阶段会停止JVM所有响应(STOP-THE-WORLD)，从根及被其引用对象开始，重新扫描 CMS 堆中残留的更新过的对象；
  • CMS-concurrent-sweep：开始并发清理阶段，在清理阶段，应用线程还在运行。
  • CMS-concurrent-reset：开始并发重置，重新初始化CMS内部数据结构，以备下一轮 GC 使用；

关于Times说明

[Times: user=1.55 sys=0.80, real=1.25 secs]
  • user：指的是cpu在用户模式下耗费的时间（不包含kernel），谨代表在当前进程中耗费的时间；
  • sys：指的是kernel耗费的cpu时间，同上，也仅代表当前进程由于调用kernel所耗费的cpu时间；
  • real：表示一次调用实际耗费时间，通俗说指的是墙上的时钟走过的时间。
  • user+sys：表示本次调用总共耗费的CPU时间，如果是多核心并发处理，实际耗费时间要小于这两个的和；

总结

根据上面的CMS日志，可以看到，一次fullGC导致的程序暂停响应的时间是0.01+0.07=0.08s
发帖者 时间： 1 条评论:
标签：

2015年12月3日星期四

Python基础备忘(一)

Python备忘

dateformat

关于dateformat的使用，有以下例子，最后有官方的directive列表，方便查询；
from datetime import datetime, date, timedelta
date_format = "%Y-%m-%dT%H:%M:%S.%fZ"
start = datetime.strftime(date.today() - timedelta(days=29), date_format)

获取当天日期对象，使用datetime中的date.today();
如果想在当前日期基础上前进或后退时间的话，可以使用datetime的timedelta，例如上例就是获取当天日期的前29天的日期对象；
datetime中的strftime将日期转为str；strptime将str转为时间；
下面是dateformat的directive列表：
DirectiveMeaningExampleNotes
%aWeekday as locale’s abbreviated name.
Sun, Mon, ..., Sat (en_US);
So, Mo, ..., Sa (de_DE)
(1)
%AWeekday as locale’s full name.
Sunday, Monday, ..., Saturday (en_US);
Sonntag, Montag, ..., Samstag (de_DE)
(1)
%wWeekday as a decimal number, where 0 is Sunday and 6 is Saturday.0, 1, ..., 6
%dDay of the month as a zero-padded decimal number.01, 02, ..., 31
%bMonth as locale’s abbreviated name.
Jan, Feb, ..., Dec (en_US);
Jan, Feb, ..., Dez (de_DE)
(1)
%BMonth as locale’s full name.
January, February, ..., December (en_US);
Januar, Februar, ..., Dezember (de_DE)
(1)
%mMonth as a zero-padded decimal number.01, 02, ..., 12
%yYear without century as a zero-padded decimal number.00, 01, ..., 99
%YYear with century as a decimal number.1970, 1988, 2001, 2013
%HHour (24-hour clock) as a zero-padded decimal number.00, 01, ..., 23
%IHour (12-hour clock) as a zero-padded decimal number.01, 02, ..., 12
%pLocale’s equivalent of either AM or PM.
AM, PM (en_US);
am, pm (de_DE)
(1), (2)
%MMinute as a zero-padded decimal number.00, 01, ..., 59
%SSecond as a zero-padded decimal number.00, 01, ..., 59(3)
%fMicrosecond as a decimal number, zero-padded on the left.000000, 000001, ..., 999999(4)
%zUTC offset in the form +HHMM or -HHMM (empty string if the the object is naive).(empty), +0000, -0400, +1030(5)
%ZTime zone name (empty string if the object is naive).(empty), UTC, EST, CST
%jDay of the year as a zero-padded decimal number.001, 002, ..., 366
%UWeek number of the year (Sunday as the first day of the week) as a zero padded decimal number. All days in a new year preceding the first Sunday are considered to be in week 0.00, 01, ..., 53(6)
%WWeek number of the year (Monday as the first day of the week) as a decimal number. All days in a new year preceding the first Monday are considered to be in week 0.00, 01, ..., 53(6)
%cLocale’s appropriate date and time representation.
Tue Aug 16 21:30:00 1988 (en_US);
Di 16 Aug 21:30:00 1988 (de_DE)
(1)
%xLocale’s appropriate date representation.
08/16/88 (None);
08/16/1988 (en_US);
16.08.1988 (de_DE)
(1)
%XLocale’s appropriate time representation.
21:30:00 (en_US);
21:30:00 (de_DE)
(1)
%%A literal '%' character.%

发送HTTP请求

使用urllib2，POST例子：
import urllib2
requrl = 'https://something.com/post_something'
headers = {'Content-Type': 'application/json'}
req = urllib2.Request(requrl, datastr, headers)
Get例子：
import urllib2
data = urllib2.urlopen("https://something.com/get_something").read()
print data

使用json

使用json解析json数据：
params = {
        "startTime": 1,
        "endTime": 1,
        "timeIncrement": "day",
        "timeMultiple": 1,
        "descending": False,
        "base": 1,
        "counter": 1
    }
datastr = json.dumps(params)#将json对象转换为str
datajson = json.loads(datastr)#将str转为json


发帖者 时间： 没有评论:
标签：
订阅： 博文 (Atom)