IBM Power 7 Problem Case: Unexpected paging resolved by disabling memory_affinity

A system running Oracle on IBMPower AIX was seeing lots of paging space traffic, and I was pulled in.  Even when paging space writes occurred, vmstat seemed to show enough server RAM to avoid paging out.  It was worse than folks originally thought in some ways: there were paging space buffer (psbuf) shortages causing additional waits in some paging space operations.  And the paging space disk was experiencing sqfull conditions according to iostat.

This is a big system.  16 memory pools because of the default cpu_scale_memp value of 8: every 8 logical CPUs gets a memory pool.  So there are 128 logical CPUs on the system: 32 Power7 cores.

With memory_affinity enabled, even though the NB_PAGES memory pool sizes were fairly well balanced, the NUMFRB free 4k frames per pool were not very well balanced.
The kdb NB_PAGES and NUMFRB values below are in hex.

(0)> memp *
                 VMP MEMP  NB_PAGES  FRAMESETS        NUMFRB
F1000F0009740000  00  000   000C9D00  000 001 002 003 00030A12
F1000F0009740500  00  001   000CA100  004 005 006 007 0000A828
F1000F0009740A00  00  002   000C9E00  008 009 00A 00B 0000B346
F1000F0009740F00  00  003   000C9300  00C 00D 00E 00F 0001EEB8
F1000F0009741400  00  004   000C9D90  010 011 012 013 000138AB
F1000F0009741900  00  005   000CAA00  014 015 016 017 00014807
F1000F0009741E00  00  006   000CA000  018 019 01A 01B 0000346E
F1000F0009742300  00  007   000C9000  01C 01D 01E 01F 0002C69A
F1000F0009742800  01  008   000C9800  020 021 022 023 0001FA32
F1000F0009742D00  01  009   000CA000  024 025 026 027 0000118B
F1000F0009743200  01  00A   000CA000  028 029 02A 02B 00011B04
F1000F0009743700  01  00B   000C9380  02C 02D 02E 02F 000131E8
F1000F0009743C00  01  00C   000C9000  030 031 032 033 00015683
F1000F0009744100  01  00D   000C9000  034 035 036 037 00003573
F1000F0009744600  01  00E   000C9000  038 039 03A 03B 000097D1
F1000F0009744B00  01  00F   000C9000  03C 03D 03E 03F 0002C819

Advised them to disable vmo parameter memory_affinity (requires bosboot and reboot).
This was what the memory pools looked like afterward.

(0)> memp *
                 VMP MEMP  NB_PAGES  FRAMESETS        NUMFRB
F1000F0009740000  00  000   000C9E00  000 001 002 003 000B3848
F1000F0009740500  00  001   000C8700  004 005 006 007 000B2952
F1000F0009740A00  00  002   000C9E00  008 009 00A 00B 000B379D
F1000F0009740F00  00  003   000C8500  00C 00D 00E 00F 000B2895
F1000F0009741400  00  004   000C8C70  010 011 012 013 000B2F53
F1000F0009741900  00  005   000CA000  014 015 016 017 000B3568
F1000F0009741E00  00  006   000CA000  018 019 01A 01B 000B3702
F1000F0009742300  00  007   000CA000  01C 01D 01E 01F 000B34CF
F1000F0009742800  00  008   000C8000  020 021 022 023 000B2E72
F1000F0009742D00  00  009   000C8000  024 025 026 027 000B305F
F1000F0009743200  00  00A   000C9000  028 029 02A 02B 000B32BA
F1000F0009743700  00  00B   000C9000  02C 02D 02E 02F 000B322C
F1000F0009743C00  00  00C   000C9000  030 031 032 033 000B3215
F1000F0009744100  00  00D   000C9000  034 035 036 037 000B3211
F1000F0009744600  00  00E   000C9000  038 039 03A 03B 000B313E
F1000F0009744B00  00  00F   000C9000  03C 03D 03E 03F 000B33C3

The memory pool NB_PAGES size have became a little more balanced with memory_affinity disabled.  But the NUMFRB numbers have become a LOT more balanced.  Excellent.  That was exactly what I wanted.  After two weeks, I was able to confirm that there had been NO paging space traffic at all based on the "paging space page ins" and "paging space page outs" reported by vmstat -s.

The absence of any paging space traffic allowed them to increase their SGA size.  That further benefited performance - significantly, actually,  In Oracle 11GR2, the small table threshold is 10% of the database cache.  Some of the SGA memory uses are fixed size - increasing SGA size can disproportionately favor the database cache.  In this case, the database cache was increased enough to bring a whole new set of high concurrency tables underneath the small table threshold.  That discouraged Oracle from performing direct path read full table scans of these tables redundantly into PGA, and instead brought more of them into SGA database cache.

I didn't even try to get more data for the memory pools in this case.  I felt bad enough about asking their administrator to run "echo 'memp *' | kdb" for me as root before and after disabling memory_affinity :).

But I felt pretty good about seeing their performance turn around.

Disabling memory_affinity is certainly not a general recommendation to address unwanted paging space use.  By disabling memory_affinity, you sacrifice a significant amount of optimization in memory latency that can be provided by keeping the memory as close as possible to the threads that use it.  But, truth be told, that optimization becomes less valuable on a large database server, with CPU cores and physical RAM that span sockets.

Why expose memory pool stats in vmstat?

Now that I have put out the request to expose memory pool stats in vmstat* I'm digging up some system stats to support the request.

I also want to lay out the argument that trying to understand memory management behavior in AIX 6.1 and AIX 7.1 without access to memory pool (and maybe even frameset) size and free size is a futile game.

I'm primarily concerned with database servers, and I've seen unexpected paging on lots and lots of IBM Power systems for a long time.  I've seen lots and lots of APARs come out for 64k page use leading to paging, the introduction of numperm_global, and on and on.  I know that there are many administrators for IBM Power database servers running AIX that have more or less given up - from their perspective some amount of paging space use just goes along with AIX and there's no use trying to fight it.  That's too bad.

I'm always trying to eliminate paging, regardless of the OS I am concerned with at the time.

So, when I saw a new set of vmo tunables introduced in AIX 7.1, I wanted to learn as much about them as possible.

Consider the vmo tunable enhanced_affinity_private.

# vmo -h enhanced_affinity_private
Help for tunable enhanced_affinity_private:
Purpose:
Specifies percentage of process private memory allocations that are affinitized by default.
Values:
        Default: 40
        Range: 0 - 100
        Type: Dynamic
        Unit: numeric
Tuning:
This tunable limits the default amount of affinitized memory allocated for process private memory.  Affinitizing private memory may improve process performance.  However, too much affinitized memory in a vmpool can cause paging and impact overall system performance.

OK... I guess 40% is a reasonable default.  How can it be evaluated?  The only way I know of evaluating would involve memory pool monitoring.

Hmmm... in there I also see enhanced_affinity_attach_limit.  What's that?

# vmo -h enhanced_affinity_attach_limit
Help for tunable enhanced_affinity_attach_limit:
Purpose:
Specifies percentage of memory allocation requests with affinity attachments that are affinitized.
Values:
        Default: 100
        Range: 0 - 100
        Type: Dynamic
        Unit: numeric
Tuning:
This tunable limits the amount of affinitized memory allocated for memory allocations that have affinity attachments.  Affinitizing such memory allocations may improve performance.  However, too much affinitzed memory in a vmpool can cause paging and impact overall system performance.

Wait a minute!  It carries the same warning that too much affinitized memory can cause paging... but its default is 100%?  That seems like something I'll want to monitor.

But before I start digging into how to monitor the effects of enhanced_affinity_attach_limit and
enhanced_affinity_private, I run across this:

IBM Power Systems Performance Guide - Implementing and Optimizing

http://www.redbooks.ibm.com/redbooks/pdfs/sg248080.pdf

(3.9 mb pdf)

Page 281

Shared memory is not impacted by the enhanced_affinity_private parameter. This kind of memory allocation is controlled by memplace_shm_named and memplace_shm_anonymous.

I've never paid attention to memplace_shm_anonymous before.  Historically it has determined first-touch or round-robin strategy for affinitized anonymous shared memory allocations.  If I had and wanted to evaluate round-robin vs first-touch... I'd probably do it by monitoring memory pool use.  Then... what if a new value sneaks in? There it is in the AIX 6.1 documentation:

Default placement of anonymous shared memory can be set to first-touch (value of 1) or round-robin across the system (value of 2) or automatic (value of 0), where the system decides the best placement for the memory.

http://pic.dhe.ibm.com/infocenter/aix/v6r1/topic/com.ibm.aix.cmds/doc/aixcmds6/vmo.htm

Truth be told, the new setting was present in the code release before it made its way into the documentation :).

http://www-01.ibm.com/support/docview.wss?uid=isg1IZ74067 

Note that AIX 7.1 on IBM Power7 memplace_shm_anonymous defaults to value 0 - system determined memory allocation.  Well... shoot... the new value is the default?  How does the system determine what strategy it'll use for allocation?  How can I evaluate whether the new "system determined" behavior is responsible for increased paging space traffic that I notice after an upgrade to AIX 7.1?

# vmo -h memplace_shm_anonymous
Help for tunable memplace_shm_anonymous:
Purpose:
Specifies the default memory placement policy for anonymous shared memory.
Values:
        Default: 0
        Range: 0 - 2
        Type: Dynamic
        Unit:
Tuning:
Anonymous shared memory refers to working storage memory, created via shmget() or mmap(), that can be accessed only by the creating process or its descendants. This memory is not associated with a name (or key). Default placement of anonymous shared memory can be set to first-touch (value of 1) or round-robin across the system (value of 2) or auto-affinitized (value of 0), where the system decides the best placement for the memory.

I've been doing this for a while - I like to keep disruptive tuning recommendations (such as changing memory_affinity or vmm_mpsize_support values) to an absolute minimum.  I also don't want to encourage a cycle of problem detection-diagnostics-fix selection-fix apply-repeat with no known end.                               

If memory pool statistics, the fundamental stats driving lrud to steal pages, are exposed, more administrators will be able to track them.  Shoot, maybe they'll even make their way into nmon :)  At any rate, it'll shed more light on the large number of cases of unexpected page outs, and it will make possible evaluating the enhanced_affinity and memplace families of vmo tunables, as well as the behavior of ASO and DSO when used.  I don't know of another method of evaluating those tunables, ASO, or DSO.

*I'll keep saying "vmstat", but I don't really care if its in vmstat or not.  I just want memory pool size, and memory pool free list size, exposed through a tool other than kdb which doesn't require root privileges to execute.

Problem case: AIX 6.1 system paging space writes in spite of sufficient free memory

I wanted to share some statistics from a few systems to show that some AIX memory management conditions are extremely difficult to understand without access to information about the amount of free memory in each of the memory pools.  Although there are ways to get this information from kdb... using kdb for monitoring doesn't seem like a great idea if there is an alternative.  Secondly, since root privileges are required to run kdb... it has to be root that runs the collection script.  I'd really like for this information to be included in something like vmstat output... but I've got to justify the value of such an enhancement. 

So I'll create a few posts with some of the numbers I've grabbed from various systems.  Places where page out to paging space is occurring, even though there sure seems like sufficient free server memory to prevent lrud from paging contents to paging space. 

Its true that there isn't much tuning that can be performed when you see that paging is due to imbalanced use of the memory pools.  But administrators don't just use systems stats for tuning feedback.  Sometimes its to diagnose a defect for which a fix is already available.  Sometimes the stats are used to get some more attention in a PMR to a condition that is likely a bug, and might be dismissed as application behavior or misconfiguration otherwise.  (I suspect that the defect fixed by recent AIX 6.1 TL6 APAR IV28494 and effecting all TLs up to AIX 7.1 TL2 could have been found and fixed a lot earlier if the pool level information could be retrieved in a less arcane manner. http://sql-sasquatch.blogspot.com/2013/08/ibm-fixes-minor-enhanced-affinity-bug.html)  Retrieving stats from the memory pool level can also build leverage for disabling memory_affinity when it would be beneficial - even though the general recommendation is to keep memory_affinity enabled in spite of memory pool imbalance.

Here's some information from a Power6 system that I gathered months ago.

[sasquatch@mtnhome] $ oslevel -s

6100-08-02-1316 

[sasquatch@mtnhome] $ lssrad -av

REF1   SRAD        MEM      CPU

0

          0   23767.31      0-19

[root@mtnhome] # echo "mempool *" |kdb
           START              END <name>
0000000000001000 0000000004160000 start+000FD8
F00000002FF47600 F00000002FFDF9C8 __ublock+000000
000000002FF22FF4 000000002FF22FF8 environ+000000
000000002FF22FF8 000000002FF22FFC errno+000000
F1000F0A00000000 F1000F0A10000000 pvproc+000000
F1000F0A10000000 F1000F0A18000000 pvthread+000000
read vscsi_scsi_ptrs OK, ptr = 0x0
(0)> mempool *
                 VMP MEMP  NB_PAGES  FRAMESETS        NUMFRB
F1000F0009740000  00  000   0023D7F0  000 001 002 003 000384E7
F1000F0009740500  00  001   0023C280  004 005 006 007 000375B0
F1000F0009740A00  01  002   000AB300  008 009 00A 00B 0001B078
F1000F0009740F00  02  003   000AB300  00C 00D 00E 00F 00012D57
 
(0)> 

So I've got two virtual memory pools, each with two memory pools.

Memory pool 001 has 2349040 4k frames and pool 002 has 2343552 4k frames - approximately 8.96 GB and 8.94 GB respectively.

Pools 002 and 003 each have 701184 4k frames - approximately 2.67 GB each.

Since the time I gathered the information above, I've switched to using the frs subcommand for these investigations.  Having the breakdown between 4k and 64k pages is especially useful.  But the decimal conversion for the free frames in each frameset is especially helpful in of-the-moment support situations.

Here's the real guts of the numbers.  Its 5:00 am to 5:40 am, with two instance of vmstat collecting information in 15 second intervals.  One instance is collecting 4k page info, the other instance collecting 64k info (that's why I've even included he two timestamps below).

Some observations:

With default minfree in place, if server memory was being used without regard to which pool its in, we wouldn't expect to see page outs of 4k pages unless the free list falls below 4 * 960 = 3840, since there are 4 pools and lrud looks at each pool freelist for the minfree threshold.

From 5:30:13 to 5:36:13, vmstat indicates at least 8682 4k pages on the freelist and at least 500 64k pages on the freelist.  But there was significant pageout activity.From 5:38:58 to 5:40:43 there were at least 9506 4k pages in the freelist and at least 588 64k pages in the freelist.  But there was significant pageout activity.

Now, at the time that I gathered this information, I didn't have my monitor written to grab information from kdb in regular intervals.  But I strongly suspected that the memory pool imbalance was problematic.

There's only one other explanation that I can think of... microbursts of memory activity, where the freelists are dipping below the minfree threshold for such a small time that the 15 second averages look they should have stayed above minfree the whole time.  I'm sure that happens sometimes... but I'm also positive that it doesn't happen frequently enough to be behind all of the examples I've seen.

time4k	avm4k	fre4k	po4k	pi4k	time64k	siz64k	avm64k	fre64k	po64k	pi64k
5:00:12	4479677	1536267	0	0	5:00:13	146351	145536	815	0	0
5:00:27	4498516	1517192	0	2	5:00:28	146351	145556	795	0	0
5:00:42	4470942	1544745	0	0	5:00:43	146351	145560	791	0	0
5:00:57	4479972	1535693	0	0	5:00:58	146351	145560	791	0	0
5:01:12	4451605	1561740	0	0	5:01:13	146351	145540	811	0	0
5:01:27	4451606	1561727	0	0	5:01:28	146351	145540	811	0	0
5:01:42	4478956	1531924	0	0	5:01:43	146351	145580	771	0	0
5:01:57	4520184	1490667	0	0	5:01:58	146351	145620	731	0	0
5:02:12	4490547	1520289	0	0	5:02:13	146351	145610	741	0	0
5:02:27	4490555	1520262	0	0	5:02:28	146351	145610	741	0	0
5:02:42	4490562	1520239	0	0	5:02:43	146351	145610	741	0	0
5:02:57	4489768	1518583	0	0	5:02:58	146351	145620	731	0	0
5:03:12	4501919	1506416	0	0	5:03:13	146351	145625	726	0	0
5:03:27	4488049	1517839	0	0	5:03:28	146351	145620	731	0	0
5:03:42	4464548	1541320	0	0	5:03:43	146351	145615	736	0	0
5:03:57	4386328	1619525	0	0	5:03:58	146351	145625	726	0	0
5:04:12	4391810	1614029	0	0	5:04:13	146351	145625	726	0	0
5:04:27	4416017	1589805	0	0	5:04:28	146351	145615	736	0	0
5:04:42	4366296	1637076	0	0	5:04:43	146351	145612	739	0	0
5:04:57	4403652	1599700	0	0	5:04:58	146351	145627	724	0	0
5:05:12	4409458	1593879	0	0	5:05:13	146351	145627	724	0	0
5:05:27	4419552	1583769	0	0	5:05:28	146351	145616	735	0	0
5:05:42	4429782	1571079	0	0	5:05:43	146351	145632	719	0	0
5:05:57	4612693	1388153	0	0	5:05:58	146351	145851	500	0	0
5:06:12	4697491	1303332	0	0	5:06:13	146415	145927	488	0	0
5:06:27	4809394	1191409	0	0	5:06:28	146415	145927	488	0	0
5:06:42	4862231	1138485	0	0	5:06:43	146415	145917	498	0	0
5:06:57	4995781	1004911	0	0	5:06:58	146415	145913	502	0	0
5:07:12	5039214	961462	0	0	5:07:13	146415	145923	492	0	0
5:07:27	5183831	816828	0	0	5:07:28	146479	146003	476	0	0
5:07:42	5470116	530524	0	0	5:07:43	146479	145993	486	0	0
5:07:57	5796571	201577	0	0	5:07:58	146479	145993	486	0	0
5:08:12	6005278	12297	0	0	5:08:13	146479	146003	476	0	0
5:08:27	6116575	9595	0	0	5:08:28	146479	146003	476	0	0
5:08:42	6280564	10865	223	16	5:08:43	146479	146014	465	0	0
5:08:57	6427583	12747	3633	51	5:08:59	146479	146014	465	0	0
5:09:12	6565990	7375	5563	79	5:09:14	146479	146024	455	0	0
5:09:27	6626389	11171	4776	513	5:09:29	146479	146027	452	0	0
5:09:42	6659459	12307	2335	137	5:09:44	146479	146026	453	0	0
5:09:57	6706790	7293	2878	165	5:09:59	146479	146026	453	0	0
5:10:12	6767226	12054	4366	114	5:10:14	146479	146036	443	0	0
5:10:27	6605343	168827	353	179	5:10:29	146479	146036	443	0	0
5:10:42	6352312	418607	0	87	5:10:44	146479	146030	449	0	0
5:10:58	6331056	439211	0	47	5:10:59	146479	146019	460	0	0
5:11:13	6345507	423647	0	69	5:11:14	146479	146029	450	0	0
5:11:28	6348486	417263	0	48	5:11:29	146479	146029	450	0	0
5:11:43	6333264	430940	0	70	5:11:44	146479	146008	471	0	0
5:11:58	6333464	429803	0	59	5:11:59	146479	146003	476	0	0
5:12:13	6330497	432209	0	35	5:12:14	146479	146008	471	0	0
5:12:28	6412141	346997	0	71	5:12:29	146479	146007	472	0	0
5:12:43	6242615	512923	0	62	5:12:44	146479	145997	482	0	0
5:12:58	6225206	526757	0	74	5:12:59	146479	145958	521	0	0
5:13:13	6005319	739394	0	111	5:13:14	146479	145959	520	0	0
5:13:28	5889966	845417	0	52	5:13:29	146479	145954	525	0	0
5:13:43	5865012	869598	0	49	5:13:44	146479	145923	556	0	0
5:13:58	5864547	869608	0	28	5:13:59	146479	145922	557	0	0
5:14:13	5869100	863449	0	45	5:14:14	146479	145937	542	0	0
5:14:28	5906781	822685	0	29	5:14:29	146479	145947	532	0	0
5:14:43	5942513	786157	0	36	5:14:44	146479	145992	487	0	0
5:14:58	6072666	652280	0	27	5:14:59	146607	146151	456	0	0
5:15:13	6364199	360084	0	18	5:15:14	146735	146263	472	0	0
5:15:28	6183692	538880	0	39	5:15:29	146735	146237	498	0	0
5:15:43	6167569	554702	0	11	5:15:44	146735	146221	514	0	0
5:15:58	6144623	577429	0	9	5:15:59	146735	146215	520	0	0
5:16:13	6238689	482966	0	24	5:16:14	146735	146216	519	0	0
5:16:28	6275805	445741	0	5	5:16:29	146735	146214	521	0	0
5:16:43	6276013	445421	0	6	5:16:44	146735	146204	531	0	0
5:16:58	6101668	619137	0	30	5:16:59	146735	146194	541	0	0
5:17:13	6002164	715473	0	8	5:17:14	146735	146200	535	0	0
5:17:28	6021171	696197	0	14	5:17:29	146735	146200	535	0	0
5:17:43	6038452	675896	0	12	5:17:44	146735	146187	548	0	0
5:17:58	6017389	696735	0	13	5:17:59	146735	146196	539	0	0
5:18:13	6001791	712107	0	13	5:18:14	146735	146215	520	0	0
5:18:28	6100299	613431	0	9	5:18:29	146735	146220	515	0	0
5:18:43	6079615	633971	0	7	5:18:44	146735	146221	514	0	0
5:18:58	6041705	669336	0	5	5:18:59	146735	146210	525	0	0
5:19:13	6054484	656472	0	4	5:19:14	146735	146218	517	0	0
5:19:28	6169205	541487	0	13	5:19:29	146735	146223	512	0	0
5:19:43	6163877	544229	0	8	5:19:44	146735	146208	527	0	0
5:19:58	6109669	598314	0	6	5:19:59	146735	146203	532	0	0
5:20:13	6114987	592856	0	5	5:20:14	146735	146214	521	0	0
5:20:28	6112390	594749	0	10	5:20:29	146735	146208	527	0	0
5:20:43	6001914	704665	0	4	5:20:44	146735	146223	512	0	0
5:20:58	5979428	724528	0	10	5:20:59	146735	146173	562	0	0
5:21:13	5910642	791703	0	7	5:21:14	146735	146019	716	0	0
5:21:28	5889066	813092	0	9	5:21:29	146735	146019	716	0	0
5:21:43	5883143	816444	0	7	5:21:44	146735	146009	726	0	0
5:21:58	5876343	823175	0	2	5:21:59	146735	145999	736	0	0
5:22:13	5805146	881064	0	57	5:22:14	146735	145849	886	0	0
5:22:28	5814261	871760	0	10	5:22:29	146735	145849	886	0	0
5:22:43	5807678	875856	0	2	5:22:44	146735	145843	892	0	0
5:22:58	5808963	874398	0	4	5:22:59	146735	145839	896	0	0
5:23:13	5813056	870219	0	2	5:23:14	146735	145849	886	0	0
5:23:28	5818436	864699	0	8	5:23:29	146735	145849	886	0	0
5:23:43	5913180	769803	0	8	5:23:44	146735	145839	896	0	0
5:23:58	5869600	810909	0	1	5:23:59	146735	145759	976	0	0
5:24:13	5874825	805585	0	5	5:24:14	146735	145769	966	0	0
5:24:28	5876120	804175	0	6	5:24:29	146735	145769	966	0	0
5:24:43	5870572	807217	0	3	5:24:44	146735	145759	976	0	0
5:24:58	5870165	807600	0	0	5:24:59	146735	145759	976	0	0
5:25:13	5874069	803290	0	2	5:25:14	146735	145764	971	0	0
5:25:28	5872311	804982	0	3	5:25:29	146735	145764	971	0	0
5:25:43	5751209	925882	0	10	5:25:44	146735	145758	977	0	0
5:25:58	5649050	1025192	0	26	5:25:59	146735	145754	981	0	0
5:26:13	5542191	1129502	0	32	5:26:14	146735	145765	970	0	0
5:26:28	5567476	1098431	0	15	5:26:29	146735	145725	1010	0	0
5:26:43	5600712	1065064	0	7	5:26:44	146735	145720	1015	0	0
5:26:58	5624397	1041331	0	1	5:26:59	146735	145715	1020	0	0
5:27:13	5678175	987526	0	0	5:27:14	146735	145725	1010	0	0
5:27:28	5801846	863766	0	4	5:27:29	146735	145725	1010	0	0
5:27:43	5909041	756520	0	1	5:27:44	146735	145714	1021	0	0
5:27:58	6115877	549614	0	3	5:27:59	146735	145754	981	0	0
5:28:13	6225719	439712	0	2	5:28:14	146735	145764	971	0	0
5:28:28	6306554	358773	0	3	5:28:29	146735	145764	971	0	0
5:28:43	6479979	182769	0	0	5:28:44	146735	145759	976	0	0
5:28:58	6477155	185558	0	1	5:28:59	146735	145754	981	0	0
5:29:13	6483916	176334	0	0	5:29:14	146735	145764	971	0	0
5:29:28	6484490	175608	0	8	5:29:29	146735	145764	971	0	0
5:29:43	6479247	180769	0	4	5:29:44	146735	145754	981	0	0
5:29:58	6619282	40561	0	5	5:29:59	146607	145758	849	0	0
5:30:13	6750035	8682	6080	27	5:30:14	146287	145769	518	0	0
5:30:28	6883368	16921	9145	305	5:30:29	146287	145783	504	0	0
5:30:43	6883675	26659	1094	472	5:30:44	146287	145773	514	0	0
5:30:58	6998652	11274	6478	60	5:30:59	146287	145764	523	0	0
5:31:13	7086547	27384	7072	215	5:31:14	146287	145723	564	0	0
5:31:28	7102757	15740	573	254	5:31:29	146287	145733	554	0	0
5:31:43	7102780	13617	416	434	5:31:44	146287	145733	554	0	0
5:31:58	7100241	15577	135	162	5:31:59	146287	145722	565	0	0
5:32:13	7094751	18266	0	154	5:32:14	146287	145717	570	0	0
5:32:28	7054339	13354	1652	194	5:32:29	146287	145711	576	0	0
5:32:43	7166779	12982	5758	286	5:32:44	146287	145713	574	0	0
5:32:58	7159540	13688	2368	1255	5:32:59	146287	145698	589	0	0
5:33:13	7160757	13392	1452	1409	5:33:14	146287	145703	584	0	0
5:33:28	7063973	13343	792	1298	5:33:29	146287	145718	569	0	0
5:33:43	7091761	23755	0	992	5:33:44	146287	145713	574	0	0
5:33:58	7124021	19774	263	939	5:33:59	146287	145713	574	0	0
5:34:13	7157841	13599	4143	719	5:34:14	146287	145712	575	0	0
5:34:28	7193086	131661	1619	1079	5:34:29	146287	145728	559	0	0
5:34:43	7194450	110482	0	1158	5:34:44	146287	145722	565	0	0
5:34:58	7223337	61679	0	1268	5:34:59	146287	145712	575	0	0
5:35:13	7257609	16065	367	1148	5:35:14	146287	145734	553	0	0
5:35:28	7294603	21833	3754	919	5:35:29	146287	145723	564	0	0
5:35:43	7328123	18004	2742	855	5:35:44	146287	145723	564	0	0
5:35:58	7433631	16793	7636	1177	5:35:59	146287	145708	579	0	0
5:36:13	7311956	122769	577	1635	5:36:14	146287	145708	579	0	0
5:36:28	7298350	121975	0	616	5:36:29	146287	145678	609	0	0
5:36:43	7200397	211287	0	551	5:36:44	146287	145679	608	0	0
5:36:58	7211599	195574	0	288	5:36:59	146287	145674	613	0	0
5:37:13	7191540	211208	0	282	5:37:14	146287	145669	618	0	0
5:37:28	7178180	218436	0	403	5:37:29	146287	145680	607	0	0
5:37:43	7199237	193189	0	276	5:37:44	146287	145680	607	0	0
5:37:58	7236189	153162	0	202	5:37:59	146287	145667	620	0	0
5:38:13	7231388	152766	0	338	5:38:14	146287	145678	609	0	0
5:38:28	7246503	131784	0	379	5:38:29	146287	145683	604	0	0
5:38:43	7332105	43150	0	196	5:38:44	146287	145683	604	0	0
5:38:58	7372058	9506	380	69	5:38:59	146287	145692	595	0	0
5:39:13	7440512	17999	5099	302	5:39:14	146287	145672	615	0	0
5:39:28	7359622	120679	1398	68	5:39:29	146287	145683	604	0	0
5:39:43	7339478	138587	0	142	5:39:44	146287	145683	604	0	0
5:39:58	7363002	106450	0	543	5:39:59	146287	145678	609	0	0
5:40:13	7486826	17715	2697	439	5:40:14	146287	145683	604	0	0
5:40:28	7533916	13249	3020	389	5:40:29	146287	145694	593	0	0
5:40:43	7149365	378542	309	413	5:40:44	146287	145699	588	0	0
5:40:58	6856467	651238	0	233	5:40:59	146287	145689	598	0	0