Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

add time when timer expired to timer events #1130

Merged
merged 2 commits into from
Apr 24, 2018

Conversation

flixr
Copy link
Contributor

@flixr flixr commented Aug 11, 2017

When the a timer expires, the callback is added to the queue.
So the callback is then then popped from the queue at some later point (for which the time is recored as current_real in the timer event).
This adds the time of when the timer actually expired to the timer event info,
in the hope that this will make debugging easier and provide a better base to test the timers.

I'm not really sure if it would be ok to add something to the timer events...
This is mainly meant as a base for discussion (see #1120 and #1129) and the possibility to test if the timer test can be improved using the current_expired time instead of current_real.

@flixr
Copy link
Contributor Author

flixr commented Aug 11, 2017

Adjusted the test to compare the expected time to when the timer expired (callback added to the queue) instead of when the callback is actually called...

Instead of adding a new current_expired time to the event, we could also change the semantics of current_real to actually contain what is now in expired here... but I think that for backwards compatibility it would be better not to change what we already have..?

@flixr flixr mentioned this pull request Aug 11, 2017
@dirk-thomas
Copy link
Member

I went ahead and merged #1132 for now since it addresses the problem by only changing the test.

If you think the changes in this patch are still useful we can keep this PR open. Currently the patch is ABI-incompatible since it e.g. inserts new arguments before existing ones.

flixr and others added 2 commits August 12, 2017 12:39
When the a timer expires, the callback is added to the queue.
So the callback is then then poped from the queue at some later point (for which the time is recored as current_real in the timer event).
This adds the time of when the timer actually expired to the timer event info,
in the hope that this will make debugging easier and provide a better base to test the timers.
Instead of checking when the callback was actually called,
check for when the timer expired (the callback was added to the callback queue) using the new current_expired time.

This *should* make the test more reliable.
@flixr
Copy link
Contributor Author

flixr commented Aug 12, 2017

Some numbers running this on my i5 laptop with stress --cpu 8 --io 8 --vm 8:
I printed the time difference of the expected time to expired, real and diff between expired and real.
It is printed as WARN if the time when the callback was actually called (real) is more than 0.1s off..

As somewhat expected the main source of the time difference is not that the timer expired too late, but that the callback is popped too late from the queue. In the late cases the time difference between timer expiration (callback gets added to queue) and when the callback is actually called is almost always over 0.1s.

[==========] Running 1 test from 1 test case.
[----------] Global test environment set-up.
[----------] 1 test from RoscppTimerCallbacks
[ RUN      ] RoscppTimerCallbacks.multipleSteadyTimeCallbacks
[ INFO] [1502542742.201425065]: expired 0.017540, real 0.044948, diff 0.027409
[ INFO] [1502542742.253723408]: expired 0.002314, real 0.012392, diff 0.010077
[ INFO] [1502542742.267024788]: expired 0.000596, real 0.010673, diff 0.010077
[ INFO] [1502542742.361639933]: expired 0.004309, real 0.005286, diff 0.000977
[ INFO] [1502542742.446833850]: expired 0.000012, real 0.005338, diff 0.005327
[ INFO] [1502542742.448853603]: expired 0.000005, real 0.007337, diff 0.007331
[ INFO] [1502542742.463131193]: expired 0.003525, real 0.006840, diff 0.003315
[ INFO] [1502542742.556760814]: expired 0.000243, real 0.000421, diff 0.000177
[ INFO] [1502542742.649003212]: expired 0.003221, real 0.007703, diff 0.004482
[ INFO] [1502542742.650711033]: expired 0.003072, real 0.009269, diff 0.006197
[ INFO] [1502542742.682347626]: expired 0.010153, real 0.025857, diff 0.015704
[ INFO] [1502542742.748412318]: expired 0.006599, real 0.006971, diff 0.000372
[ INFO] [1502542742.762432052]: expired 0.000213, real 0.005917, diff 0.005703
[ INFO] [1502542742.845885941]: expired 0.000032, real 0.004598, diff 0.004566
[ INFO] [1502542742.847533097]: expired 0.000012, real 0.006049, diff 0.006036
[ INFO] [1502542742.868078012]: expired 0.001355, real 0.011620, diff 0.010266
[ INFO] [1502542742.958188828]: expired 0.000332, real 0.001895, diff 0.001563
[ INFO] [1502542743.042393983]: expired 0.000009, real 0.001080, diff 0.001072
[ INFO] [1502542743.044841212]: expired 0.000003, real 0.003381, diff 0.003378
[ INFO] [1502542743.046137157]: expired 0.000007, real 0.004717, diff 0.004710
[ INFO] [1502542743.047929060]: expired 0.000005, real 0.006360, diff 0.006354
[ INFO] [1502542743.067811726]: expired 0.000954, real 0.011280, diff 0.010326
[ INFO] [1502542743.166616196]: expired 0.000212, real 0.010317, diff 0.010105
[ INFO] [1502542743.251892755]: expired 0.000100, real 0.010400, diff 0.010301
[ INFO] [1502542743.254176625]: expired 0.000004, real 0.012487, diff 0.012483
[ INFO] [1502542743.269248446]: expired 0.003312, real 0.012955, diff 0.009643
[ INFO] [1502542743.345228306]: expired 0.000804, real 0.003806, diff 0.003001
[ INFO] [1502542743.346644475]: expired 0.000838, real 0.005184, diff 0.004346
[ INFO] [1502542743.360014706]: expired 0.000103, real 0.003679, diff 0.003576
[ INFO] [1502542743.444509574]: expired 0.000034, real 0.003205, diff 0.003171
[ INFO] [1502542743.445797742]: expired 0.000010, real 0.004338, diff 0.004328
[ INFO] [1502542743.448017899]: expired 0.000019, real 0.006132, diff 0.006113
[ INFO] [1502542743.470960517]: expired 0.008251, real 0.014672, diff 0.006421
[ INFO] [1502542743.559588077]: expired 0.000016, real 0.003246, diff 0.003230
[ INFO] [1502542743.642179458]: expired 0.000147, real 0.000676, diff 0.000529
[ INFO] [1502542743.643980495]: expired 0.000150, real 0.002555, diff 0.002406
[ INFO] [1502542743.646271411]: expired 0.000065, real 0.004738, diff 0.004673
[ INFO] [1502542743.649068788]: expired 0.000029, real 0.007372, diff 0.007343
[ INFO] [1502542743.665871529]: expired 0.000911, real 0.009350, diff 0.008439
[ INFO] [1502542743.761145799]: expired 0.000227, real 0.004844, diff 0.004618
[ INFO] [1502542743.843859701]: expired 0.000041, real 0.002291, diff 0.002250
[ INFO] [1502542743.856138358]: expired 0.005395, real 0.014653, diff 0.009258
[ INFO] [1502542743.857600504]: expired 0.005399, real 0.016106, diff 0.010708
[ INFO] [1502542743.859155637]: expired 0.005222, real 0.017432, diff 0.012211
[ INFO] [1502542743.872935052]: expired 0.006567, real 0.016647, diff 0.010080
[ INFO] [1502542743.945700082]: expired 0.000335, real 0.004116, diff 0.003780
[ INFO] [1502542743.947822296]: expired 0.000247, real 0.006180, diff 0.005933
[ INFO] [1502542743.962761933]: expired 0.000221, real 0.006434, diff 0.006213
[ INFO] [1502542744.045878171]: expired 0.001026, real 0.004567, diff 0.003542
[ INFO] [1502542744.047787269]: expired 0.000604, real 0.006090, diff 0.005486
[ INFO] [1502542744.063298907]: expired 0.000361, real 0.007008, diff 0.006647
[ INFO] [1502542744.158427757]: expired 0.000224, real 0.002090, diff 0.001866
[ INFO] [1502542744.251022597]: expired 0.003316, real 0.009741, diff 0.006426
[ INFO] [1502542744.252460098]: expired 0.003317, real 0.011025, diff 0.007708
[ INFO] [1502542744.253767758]: expired 0.003297, real 0.012326, diff 0.009030
[ INFO] [1502542744.255014086]: expired 0.003240, real 0.013533, diff 0.010292
[ INFO] [1502542744.256317342]: expired 0.003183, real 0.014732, diff 0.011549
[ INFO] [1502542744.259159391]: expired 0.003003, real 0.017346, diff 0.014343
[ INFO] [1502542744.275890641]: expired 0.003083, real 0.019574, diff 0.016491
[ INFO] [1502542744.353018527]: expired 0.001425, real 0.011476, diff 0.010051
[ INFO] [1502542744.366335725]: expired 0.000444, real 0.009750, diff 0.009306
[ INFO] [1502542744.448811978]: expired 0.003236, real 0.007498, diff 0.004262
[ INFO] [1502542744.450455852]: expired 0.002716, real 0.008650, diff 0.005934
[ INFO] [1502542744.464222467]: expired 0.004223, real 0.007932, diff 0.003709
[ INFO] [1502542744.546755970]: expired 0.003097, real 0.005329, diff 0.002232
[ INFO] [1502542744.548657017]: expired 0.002940, real 0.006972, diff 0.004033
[ INFO] [1502542744.561777563]: expired 0.000216, real 0.005483, diff 0.005267
[ INFO] [1502542744.654715303]: expired 0.003251, real 0.013382, diff 0.010131
[ INFO] [1502542744.656387644]: expired 0.003110, real 0.014908, diff 0.011798
[ INFO] [1502542744.657852105]: expired 0.003018, real 0.016307, diff 0.013289
[ INFO] [1502542744.659366723]: expired 0.002687, real 0.017397, diff 0.014711
[ INFO] [1502542744.673211547]: expired 0.006753, real 0.016870, diff 0.010117
[ INFO] [1502542744.757674301]: expired 0.000262, real 0.001371, diff 0.001109
[ INFO] [1502542744.850028126]: expired 0.000671, real 0.008730, diff 0.008059
[ INFO] [1502542744.851482694]: expired 0.000554, real 0.010027, diff 0.009473
[ INFO] [1502542744.853432731]: expired 0.000496, real 0.011946, diff 0.011450
[ INFO] [1502542744.855259687]: expired 0.000467, real 0.013752, diff 0.013285
[ INFO] [1502542744.857821393]: expired 0.000319, real 0.016139, diff 0.015820
[ INFO] [1502542744.859758615]: expired 0.000054, real 0.017829, diff 0.017775
[ INFO] [1502542744.873522594]: expired 0.003581, real 0.016937, diff 0.013357
[ INFO] [1502542744.959576169]: expired 0.000213, real 0.003247, diff 0.003034
[ INFO] [1502542745.052167170]: expired 0.000809, real 0.010881, diff 0.010072
[ INFO] [1502542745.055103404]: expired 0.000691, real 0.013635, diff 0.012944
[ INFO] [1502542745.056326372]: expired 0.000564, real 0.014780, diff 0.014216
[ INFO] [1502542745.059043941]: expired 0.000169, real 0.017025, diff 0.016856
[ INFO] [1502542745.073223809]: expired 0.006407, real 0.016666, diff 0.010259
[ INFO] [1502542745.151294306]: expired 0.000018, real 0.009728, diff 0.009710
[ INFO] [1502542745.153004959]: expired 0.000006, real 0.011238, diff 0.011232
[ INFO] [1502542745.165619641]: expired 0.000009, real 0.009321, diff 0.009312
[ INFO] [1502542745.248795347]: expired 0.003228, real 0.007487, diff 0.004259
[ INFO] [1502542745.250304293]: expired 0.002484, real 0.008243, diff 0.005759
[ INFO] [1502542745.265049315]: expired 0.004371, real 0.008401, diff 0.004031
[ INFO] [1502542745.349868565]: expired 0.001343, real 0.008362, diff 0.007020
[ INFO] [1502542745.352297244]: expired 0.001316, real 0.010598, diff 0.009282
[ INFO] [1502542745.371836926]: expired 0.002230, real 0.015495, diff 0.013265
[ INFO] [1502542745.449120657]: expired 0.000016, real 0.007646, diff 0.007630
[ INFO] [1502542745.451323044]: expired 0.000011, real 0.009914, diff 0.009903
[ INFO] [1502542745.453866820]: expired 0.000010, real 0.012412, diff 0.012402
[ INFO] [1502542745.456158200]: expired 0.000006, real 0.014646, diff 0.014640
[ INFO] [1502542745.458746599]: expired 0.000007, real 0.017021, diff 0.017014
[ INFO] [1502542745.472914517]: expired 0.000004, real 0.031114, diff 0.031111
[ INFO] [1502542745.479159029]: expired 0.000017, real 0.036993, diff 0.036976
[ INFO] [1502542745.549519603]: expired 0.007158, real 0.092967, diff 0.085809
[ INFO] [1502542745.595682407]: expired 0.020901, real 0.039235, diff 0.018333
[ INFO] [1502542745.643140778]: expired 0.000065, real 0.001658, diff 0.001593
[ INFO] [1502542745.645719289]: expired 0.000033, real 0.003482, diff 0.003449
[ INFO] [1502542745.659728722]: expired 0.000293, real 0.003425, diff 0.003132
[ INFO] [1502542745.743397784]: expired 0.000324, real 0.001915, diff 0.001591
[ INFO] [1502542745.745549713]: expired 0.000042, real 0.003711, diff 0.003668
[ INFO] [1502542745.759520004]: expired 0.000524, real 0.003220, diff 0.002696
[ INFO] [1502542745.855174485]: expired 0.003837, real 0.013854, diff 0.010018
[ INFO] [1502542745.858785149]: expired 0.003695, real 0.016994, diff 0.013299
[ INFO] [1502542745.863885700]: expired 0.003670, real 0.022395, diff 0.018726
[ INFO] [1502542745.866300228]: expired 0.003574, real 0.024677, diff 0.021103
[ INFO] [1502542745.869212685]: expired 0.003497, real 0.027478, diff 0.023981
[ INFO] [1502542745.879276760]: expired 0.002862, real 0.036937, diff 0.034075
[ INFO] [1502542745.929948599]: expired 0.007707, real 0.073644, diff 0.065937
[ INFO] [1502542745.970695109]: expired 0.000594, real 0.014393, diff 0.013799
[ INFO] [1502542746.054165283]: expired 0.002760, real 0.012856, diff 0.010096
[ INFO] [1502542746.055983664]: expired 0.002650, real 0.014566, diff 0.011916
[ INFO] [1502542746.058636427]: expired 0.002560, real 0.017067, diff 0.014507
[ INFO] [1502542746.061487773]: expired 0.002535, real 0.019906, diff 0.017372
[ INFO] [1502542746.064192572]: expired 0.002205, real 0.022295, diff 0.020090
[ INFO] [1502542746.073482674]: expired 0.001698, real 0.031059, diff 0.029361
[ INFO] [1502542746.127447151]: expired 0.008320, real 0.071127, diff 0.062807
[ INFO] [1502542746.178301676]: expired 0.011847, real 0.021990, diff 0.010143
[ INFO] [1502542746.253692727]: expired 0.002305, real 0.012381, diff 0.010077
[ INFO] [1502542746.255828088]: expired 0.002193, real 0.014388, diff 0.012195
[ INFO] [1502542746.258773663]: expired 0.001930, real 0.017057, diff 0.015127
[ INFO] [1502542746.261782950]: expired 0.001170, real 0.019281, diff 0.018111
[ INFO] [1502542746.277451656]: expired 0.005607, real 0.020962, diff 0.015355
[ INFO] [1502542746.366945679]: expired 0.017481, real 0.025499, diff 0.008018
[ INFO] [1502542746.369612327]: expired 0.017458, real 0.028086, diff 0.010628
[ INFO] [1502542746.372979912]: expired 0.017329, real 0.031320, diff 0.013991
[ INFO] [1502542746.381696242]: expired 0.017017, real 0.039735, diff 0.022718
[ INFO] [1502542746.395134964]: expired 0.002710, real 0.038831, diff 0.036121
[ INFO] [1502542746.450162118]: expired 0.000014, real 0.008836, diff 0.008822
[ INFO] [1502542746.453457940]: expired 0.000008, real 0.010847, diff 0.010839
[ INFO] [1502542746.474351649]: expired 0.002082, real 0.018036, diff 0.015955
[ INFO] [1502542746.565094106]: expired 0.000418, real 0.008768, diff 0.008350
[ INFO] [1502542746.648336939]: expired 0.003229, real 0.007000, diff 0.003771
[ INFO] [1502542746.650622763]: expired 0.003124, real 0.009231, diff 0.006107
[ INFO] [1502542746.653503665]: expired 0.003100, real 0.012045, diff 0.008945
[ INFO] [1502542746.655794356]: expired 0.003040, real 0.014263, diff 0.011223
[ INFO] [1502542746.663853536]: expired 0.002978, real 0.022059, diff 0.019081
[ INFO] [1502542746.685015318]: expired 0.002795, real 0.043215, diff 0.040420
[ INFO] [1502542746.703383846]: expired 0.002585, real 0.061336, diff 0.058751
[ INFO] [1502542746.718485035]: expired 0.001886, real 0.075569, diff 0.073683
[ INFO] [1502542746.755128942]: expired 0.004871, real 0.098834, diff 0.093963
[ INFO] [1502542746.767153774]: expired 0.002963, real 0.025601, diff 0.022638
[ INFO] [1502542746.814031826]: expired 0.011020, real 0.057640, diff 0.046620
[ INFO] [1502542746.842406640]: expired 0.000647, real 0.000955, diff 0.000308
[ INFO] [1502542746.847147222]: expired 0.000539, real 0.005648, diff 0.005109
[ INFO] [1502542746.871685920]: expired 0.000368, real 0.029994, diff 0.029626
[ INFO] [1502542746.908646310]: expired 0.000063, real 0.065795, diff 0.065732
[ INFO] [1502542746.942216705]: expired 0.004237, real 0.070564, diff 0.066328
[ INFO] [1502542746.979900203]: expired 0.000035, real 0.038301, diff 0.038266
[ INFO] [1502542746.983782578]: expired 0.000572, real 0.041713, diff 0.041141
[ INFO] [1502542747.024089160]: expired 0.008546, real 0.067780, diff 0.059234
[ INFO] [1502542747.049836792]: expired 0.000035, real 0.008519, diff 0.008484
[ INFO] [1502542747.052507523]: expired 0.003058, real 0.011042, diff 0.007984
[ INFO] [1502542747.054963326]: expired 0.002724, real 0.013143, diff 0.010419
[ INFO] [1502542747.093396822]: expired 0.001639, real 0.050448, diff 0.048809
[ INFO] [1502542747.127678636]: expired 0.000009, real 0.071367, diff 0.071358
[ INFO] [1502542747.162733250]: expired 0.000113, real 0.006382, diff 0.006269
[ INFO] [1502542747.247069015]: expired 0.000045, real 0.005773, diff 0.005727
[ INFO] [1502542747.248951943]: expired 0.000057, real 0.007520, diff 0.007463
[ INFO] [1502542747.250821063]: expired 0.000021, real 0.009287, diff 0.009266
[ INFO] [1502542747.254049368]: expired 0.000014, real 0.012405, diff 0.012391
[ INFO] [1502542747.260319054]: expired 0.002367, real 0.018003, diff 0.015636
[ INFO] [1502542747.272258780]: expired 0.001490, real 0.029196, diff 0.027706
[ INFO] [1502542747.309297263]: expired 0.004438, real 0.052983, diff 0.048545
[ INFO] [1502542747.346571861]: expired 0.000023, real 0.005024, diff 0.005001
[ INFO] [1502542747.349405728]: expired 0.000012, real 0.007675, diff 0.007663
[ INFO] [1502542747.386708242]: expired 0.002920, real 0.030396, diff 0.027475
[ INFO] [1502542747.449245132]: expired 0.003257, real 0.007947, diff 0.004690
[ INFO] [1502542747.452164552]: expired 0.003140, real 0.010493, diff 0.007353
[ INFO] [1502542747.460720348]: expired 0.003050, real 0.019153, diff 0.016103
[ INFO] [1502542747.493689693]: expired 0.003020, real 0.051691, diff 0.048671
[ INFO] [1502542747.513507934]: expired 0.002728, real 0.071561, diff 0.068833
[ INFO] [1502542747.523449665]: expired 0.001441, real 0.080252, diff 0.078811
[ WARN] [1502542747.561546130]: expired 0.000501, real 0.104931, diff 0.104430
[ INFO] [1502542747.571206970]: expired 0.000015, real 0.029758, diff 0.029743
[ INFO] [1502542747.586457887]: expired 0.000015, real 0.044043, diff 0.044028
[ INFO] [1502542747.603401506]: expired 0.016221, real 0.047066, diff 0.030845
[ INFO] [1502542747.654149878]: expired 0.002838, real 0.012830, diff 0.009992
[ INFO] [1502542747.658177636]: expired 0.000910, real 0.014842, diff 0.013931
[ INFO] [1502542747.673331043]: expired 0.004562, real 0.017031, diff 0.012469
[ INFO] [1502542747.761584590]: expired 0.002223, real 0.005289, diff 0.003065
[ INFO] [1502542747.846830024]: expired 0.000058, real 0.005524, diff 0.005467
[ INFO] [1502542747.848917850]: expired 0.000100, real 0.007498, diff 0.007398
[ INFO] [1502542747.850628866]: expired 0.000092, real 0.009199, diff 0.009107
[ INFO] [1502542747.853390115]: expired 0.000074, real 0.011899, diff 0.011825
[ INFO] [1502542747.865670491]: expired 0.000061, real 0.023028, diff 0.022968
[ INFO] [1502542747.881281658]: expired 0.000029, real 0.039296, diff 0.039267
[ INFO] [1502542747.891812969]: expired 0.000017, real 0.050026, diff 0.050009
[ INFO] [1502542747.908448003]: expired 0.002575, real 0.066478, diff 0.063903
[ WARN] [1502542747.956646241]: expired 0.002233, real 0.114255, diff 0.112022
[ WARN] [1502542747.963475913]: expired 0.001085, real 0.120001, diff 0.118916
[ WARN] [1502542747.997402054]: expired 0.009338, real 0.140810, diff 0.131472
[ INFO] [1502542748.049212760]: expired 0.056861, real 0.092908, diff 0.036046
[ INFO] [1502542748.061213175]: expired 0.001815, real 0.019922, diff 0.018107
[ INFO] [1502542748.074792520]: expired 0.000011, real 0.031162, diff 0.031151
[ INFO] [1502542748.144663828]: expired 0.005085, real 0.088348, diff 0.083263
[ INFO] [1502542748.171746589]: expired 0.003089, real 0.030305, diff 0.027216
[ INFO] [1502542748.174254914]: expired 0.002996, real 0.032690, diff 0.029693
[ INFO] [1502542748.185576218]: expired 0.002933, real 0.043933, diff 0.041000
[ INFO] [1502542748.191379397]: expired 0.002161, real 0.048972, diff 0.046811
[ INFO] [1502542748.211602692]: expired 0.004794, real 0.055265, diff 0.050471
[ INFO] [1502542748.262145919]: expired 0.003219, real 0.020861, diff 0.017641
[ INFO] [1502542748.272569021]: expired 0.003080, real 0.031096, diff 0.028016
[ INFO] [1502542748.295567504]: expired 0.002953, real 0.053913, diff 0.050960
[ INFO] [1502542748.311526710]: expired 0.002556, real 0.069518, diff 0.066963
[ WARN] [1502542748.350321343]: expired 0.000791, real 0.106431, diff 0.105640
[ WARN] [1502542748.375639900]: expired 0.000623, real 0.119302, diff 0.118678
[ INFO] [1502542748.434751597]: expired 0.001991, real 0.093247, diff 0.091256
[ INFO] [1502542748.437323595]: expired 0.001758, real 0.095483, diff 0.093725
[ WARN] [1502542748.463770009]: expired 0.045712, real 0.107209, diff 0.061497
[ INFO] [1502542748.501570389]: expired 0.000062, real 0.060139, diff 0.060076
[ INFO] [1502542748.517249370]: expired 0.000011, real 0.075801, diff 0.075789
[ INFO] [1502542748.541481099]: expired 0.000506, real 0.095962, diff 0.095456
[ WARN] [1502542748.557881458]: expired 0.000359, real 0.116138, diff 0.115779
[ WARN] [1502542748.579297922]: expired 0.003549, real 0.136550, diff 0.133002
[ WARN] [1502542748.615292994]: expired 0.002239, real 0.171370, diff 0.169131
[ WARN] [1502542748.672751104]: expired 0.034846, real 0.216444, diff 0.181599
[ INFO] [1502542748.705222278]: expired 0.000719, real 0.063690, diff 0.062971
[ WARN] [1502542748.761108543]: expired 0.000578, real 0.112702, diff 0.112124
[ WARN] [1502542748.775181842]: expired 0.000020, real 0.133100, diff 0.133081
[ WARN] [1502542748.796736819]: expired 0.000039, real 0.152588, diff 0.152549
[ WARN] [1502542748.810147494]: expired 0.009920, real 0.131336, diff 0.121415
[ WARN] [1502542748.864813717]: expired 0.007708, real 0.123373, diff 0.115665
[ WARN] [1502542748.867888336]: expired 0.006571, real 0.125170, diff 0.118600
[ WARN] [1502542748.894249064]: expired 0.072510, real 0.115533, diff 0.043023
[ INFO] [1502542748.902244581]: expired 0.009965, real 0.060941, diff 0.050976
[ INFO] [1502542748.915193306]: expired 0.009764, real 0.073699, diff 0.063935
[ WARN] [1502542748.943478271]: expired 0.009706, real 0.101904, diff 0.092198
[ WARN] [1502542748.957641051]: expired 0.009591, real 0.115928, diff 0.106337
[ WARN] [1502542748.963322447]: expired 0.009383, real 0.121433, diff 0.112049
[ WARN] [1502542748.997751239]: expired 0.006970, real 0.153203, diff 0.146233
[ WARN] [1502542749.042918834]: expired 0.023508, real 0.164023, diff 0.140515
[ INFO] [1502542749.087436796]: expired 0.001000, real 0.046106, diff 0.045105
[ INFO] [1502542749.106271191]: expired 0.000983, real 0.064699, diff 0.063717
[ WARN] [1502542749.149324974]: expired 0.000962, real 0.107844, diff 0.106882
[ WARN] [1502542749.157265729]: expired 0.000906, real 0.115702, diff 0.114796
[ WARN] [1502542749.207444596]: expired 0.000847, real 0.165851, diff 0.165004
[ WARN] [1502542749.228874220]: expired 0.000820, real 0.187062, diff 0.186242
[ WARN] [1502542749.253579836]: expired 0.000674, real 0.211773, diff 0.211100
[ WARN] [1502542749.273190871]: expired 0.000328, real 0.231017, diff 0.230688
[ WARN] [1502542749.299891777]: expired 0.000445, real 0.257151, diff 0.256706
[ WARN] [1502542749.306563865]: expired 0.001260, real 0.262047, diff 0.260787
[ WARN] [1502542749.312356531]: expired 0.072832, real 0.333644, diff 0.260812
[ WARN] [1502542749.362424118]: expired 0.003249, real 0.121127, diff 0.117878
[ WARN] [1502542749.388335150]: expired 0.003823, real 0.143529, diff 0.139706
[ INFO] [1502542749.413857176]: expired 0.010128, real 0.088434, diff 0.078305
[ INFO] [1502542749.419050016]: expired 0.021339, real 0.077604, diff 0.056266
[ INFO] [1502542749.423310106]: expired 0.021296, real 0.081801, diff 0.060505
[ WARN] [1502542749.459404167]: expired 0.020847, real 0.117200, diff 0.096353
[ WARN] [1502542749.487807155]: expired 0.019990, real 0.144996, diff 0.125005
[ INFO] [1502542749.512628781]: expired 0.001474, real 0.087149, diff 0.085674
[ WARN] [1502542749.558182610]: expired 0.003278, real 0.116653, diff 0.113375
[ WARN] [1502542749.566276073]: expired 0.003182, real 0.124820, diff 0.121637
[ WARN] [1502542749.587690827]: expired 0.002434, real 0.145434, diff 0.143000
[ WARN] [1502542749.600488396]: expired 0.000024, real 0.155521, diff 0.155497
[ INFO] [1502542749.615854994]: expired 0.032399, real 0.090443, diff 0.058044
[ WARN] [1502542749.642258472]: expired 0.016470, real 0.100701, diff 0.084230
[ WARN] [1502542749.645307285]: expired 0.016307, real 0.103535, diff 0.087228
[ INFO] [1502542749.664817827]: expired 0.016819, real 0.039354, diff 0.022535
[ INFO] [1502542749.667064908]: expired 0.000973, real 0.025780, diff 0.024807
[ INFO] [1502542749.672725433]: expired 0.000834, real 0.031231, diff 0.030397
[ INFO] [1502542749.680865048]: expired 0.000740, real 0.039339, diff 0.038598
[ INFO] [1502542749.693093705]: expired 0.000435, real 0.051200, diff 0.050765
[ INFO] [1502542749.710504220]: expired 0.000017, real 0.067502, diff 0.067485
[ INFO] [1502542749.712912792]: expired 0.000049, real 0.067628, diff 0.067579
[ INFO] [1502542749.760316102]: expired 0.023384, real 0.034886, diff 0.011502
[ INFO] [1502542749.845259506]: expired 0.017404, real 0.019813, diff 0.002409
[ INFO] [1502542749.846728247]: expired 0.001556, real 0.005462, diff 0.003905
[ INFO] [1502542749.849633573]: expired 0.001385, real 0.008192, diff 0.006807
[ INFO] [1502542749.851597909]: expired 0.001357, real 0.010105, diff 0.008748
[ INFO] [1502542749.860256689]: expired 0.001260, real 0.018543, diff 0.017284
[ INFO] [1502542749.862187387]: expired 0.001180, real 0.020515, diff 0.019334
[ INFO] [1502542749.867427896]: expired 0.000863, real 0.025332, diff 0.024469
[ INFO] [1502542749.880972416]: expired 0.000548, real 0.038622, diff 0.038073
[ INFO] [1502542749.910607062]: expired 0.014970, real 0.065213, diff 0.050244
[ INFO] [1502542749.942495632]: expired 0.000018, real 0.016821, diff 0.016803
[ INFO] [1502542749.958647072]: expired 0.006322, real 0.017202, diff 0.010880
[ INFO] [1502542749.961028325]: expired 0.006197, real 0.019418, diff 0.013222
[ INFO] [1502542749.975177681]: expired 0.004782, real 0.026321, diff 0.021539
[ INFO] [1502542750.037125827]: expired 0.003104, real 0.011717, diff 0.008613
[ INFO] [1502542750.048682778]: expired 0.003353, real 0.007402, diff 0.004049
[ INFO] [1502542750.050227178]: expired 0.000023, real 0.004638, diff 0.004615
[ INFO] [1502542750.127547106]: expired 0.000012, real 0.002134, diff 0.002122
[ INFO] [1502542750.234891438]: expired 0.003119, real 0.009485, diff 0.006367
[ INFO] [1502542750.250436416]: expired 0.003224, real 0.009116, diff 0.005893
[ INFO] [1502542750.254257006]: expired 0.003112, real 0.012799, diff 0.009687
[ INFO] [1502542750.256222424]: expired 0.003087, real 0.014785, diff 0.011698
[ INFO] [1502542750.257844856]: expired 0.003026, real 0.016347, diff 0.013321
[ INFO] [1502542750.259619514]: expired 0.002999, real 0.018065, diff 0.015066
[ INFO] [1502542750.270390197]: expired 0.002779, real 0.028512, diff 0.025733
[ INFO] [1502542750.275544280]: expired 0.002673, real 0.033675, diff 0.031002
[ INFO] [1502542750.290572539]: expired 0.002164, real 0.048166, diff 0.046002
[ INFO] [1502542750.296050092]: expired 0.001388, real 0.052874, diff 0.051486
[ INFO] [1502542750.318800704]: expired 0.008351, real 0.072763, diff 0.064411
[ INFO] [1502542750.408684883]: expired 0.000037, real 0.083229, diff 0.083192
[ INFO] [1502542750.410187316]: expired 0.003111, real 0.068715, diff 0.065604
[ INFO] [1502542750.411474196]: expired 0.002662, real 0.069457, diff 0.066795
[ INFO] [1502542750.431201739]: expired 0.000030, real 0.005785, diff 0.005755
[ INFO] [1502542750.450819408]: expired 0.007986, real 0.009531, diff 0.001545
[ INFO] [1502542750.452180066]: expired 0.003218, real 0.006090, diff 0.002871
[ INFO] [1502542750.536720906]: expired 0.006900, real 0.011037, diff 0.004137
[ INFO] [1502542750.548553754]: expired 0.003106, real 0.007123, diff 0.004017
[ INFO] [1502542750.549876169]: expired 0.001237, real 0.006569, diff 0.005332
[ INFO] [1502542750.642140708]: expired 0.015334, real 0.016731, diff 0.001397
[ INFO] [1502542750.654880426]: expired 0.002181, real 0.013561, diff 0.011380
[ INFO] [1502542750.656186391]: expired 0.002032, real 0.014731, diff 0.012698
[ INFO] [1502542750.657372556]: expired 0.001905, real 0.015796, diff 0.013892
[ INFO] [1502542750.658528770]: expired 0.001771, real 0.016821, diff 0.015050
[ INFO] [1502542750.659812160]: expired 0.001006, real 0.017331, diff 0.016325
[ INFO] [1502542750.661249730]: expired 0.000007, real 0.014925, diff 0.014918
[ INFO] [1502542750.737168460]: expired 0.001464, real 0.011544, diff 0.010080
[ INFO] [1502542750.838235914]: expired 0.006734, real 0.012635, diff 0.005901
[ INFO] [1502542750.851518672]: expired 0.000050, real 0.010202, diff 0.010153
[ INFO] [1502542750.852850387]: expired 0.000008, real 0.011379, diff 0.011371
[ INFO] [1502542750.854265640]: expired 0.000013, real 0.012771, diff 0.012758
[ INFO] [1502542750.855500362]: expired 0.000002, real 0.013996, diff 0.013994
[ INFO] [1502542750.856783604]: expired 0.000006, real 0.015166, diff 0.015160
[ INFO] [1502542750.857963657]: expired 0.000004, real 0.016308, diff 0.016304
[ INFO] [1502542750.859161954]: expired 0.000010, real 0.017233, diff 0.017223
[ INFO] [1502542750.868579460]: expired 0.000006, real 0.026416, diff 0.026410
[ INFO] [1502542750.886166147]: expired 0.000018, real 0.042573, diff 0.042555
[ INFO] [1502542750.887803389]: expired 0.001944, real 0.041211, diff 0.039267
[ INFO] [1502542750.938787042]: expired 0.010406, real 0.013370, diff 0.002963
[ INFO] [1502542750.950669320]: expired 0.000459, real 0.008888, diff 0.008429
[ INFO] [1502542750.952835807]: expired 0.000210, real 0.010992, diff 0.010783
[ INFO] [1502542751.036382885]: expired 0.008482, real 0.010918, diff 0.002436
[ INFO] [1502542751.048199802]: expired 0.000021, real 0.006905, diff 0.006884
[ INFO] [1502542751.049786816]: expired 0.000479, real 0.008329, diff 0.007850
[ INFO] [1502542751.061469954]: expired 0.015105, real 0.018786, diff 0.003681
[ INFO] [1502542751.062909933]: expired 0.010729, real 0.015908, diff 0.005179
[ INFO] [1502542751.136912090]: expired 0.000927, real 0.011279, diff 0.010352
[ INFO] [1502542751.148628777]: expired 0.003181, real 0.007205, diff 0.004023
[ INFO] [1502542751.150081107]: expired 0.001020, real 0.006480, diff 0.005460
[ INFO] [1502542751.233758950]: expired 0.003199, real 0.008346, diff 0.005147
[ INFO] [1502542751.245289258]: expired 0.003233, real 0.003992, diff 0.000760
[ INFO] [1502542751.260192929]: expired 0.000005, real 0.012723, diff 0.012719
[ INFO] [1502542751.335665110]: expired 0.000175, real 0.010257, diff 0.010082
[ INFO] [1502542751.347414053]: expired 0.003082, real 0.005922, diff 0.002840
[ INFO] [1502542751.348841610]: expired 0.002462, real 0.006611, diff 0.004149
[ INFO] [1502542751.445222142]: expired 0.010555, real 0.019651, diff 0.009096
[ INFO] [1502542751.446954216]: expired 0.000041, real 0.005617, diff 0.005576
[ INFO] [1502542751.448548371]: expired 0.000029, real 0.007102, diff 0.007073
[ INFO] [1502542751.449902242]: expired 0.000013, real 0.008400, diff 0.008387
[ INFO] [1502542751.451228186]: expired 0.003036, real 0.009694, diff 0.006658
[ INFO] [1502542751.453577830]: expired 0.003042, real 0.011849, diff 0.008807
[ INFO] [1502542751.454853068]: expired 0.002864, real 0.013057, diff 0.010193
[ INFO] [1502542751.456011814]: expired 0.002655, real 0.014046, diff 0.011391
[ INFO] [1502542751.473839201]: expired 0.001961, real 0.030866, diff 0.028905
[ INFO] [1502542751.475954030]: expired 0.000901, real 0.032049, diff 0.031148
[ INFO] [1502542751.514222644]: expired 0.013897, real 0.066653, diff 0.052757
[ INFO] [1502542751.548645119]: expired 0.008678, real 0.023195, diff 0.014517
[ INFO] [1502542751.643535855]: expired 0.015894, real 0.017950, diff 0.002056
[ INFO] [1502542751.644806120]: expired 0.000149, real 0.003543, diff 0.003394
[ INFO] [1502542751.646182765]: expired 0.000010, real 0.004648, diff 0.004638
[ INFO] [1502542751.647634162]: expired 0.000009, real 0.005710, diff 0.005701
[ INFO] [1502542751.659168858]: expired 0.001221, real 0.011303, diff 0.010082
[ INFO] [1502542751.732301799]: expired 0.000012, real 0.006886, diff 0.006874
[ INFO] [1502542751.753893754]: expired 0.002363, real 0.012462, diff 0.010099
[ INFO] [1502542751.755389074]: expired 0.002192, real 0.013694, diff 0.011501
[ INFO] [1502542751.756900990]: expired 0.002093, real 0.015146, diff 0.013053
[ INFO] [1502542751.758527925]: expired 0.000003, real 0.014512, diff 0.014509
[ INFO] [1502542751.830840853]: expired 0.000007, real 0.005300, diff 0.005293
[ INFO] [1502542751.853675534]: expired 0.002369, real 0.012395, diff 0.010026
[ INFO] [1502542751.855335174]: expired 0.002242, real 0.013712, diff 0.011470
[ INFO] [1502542751.857418190]: expired 0.002217, real 0.015817, diff 0.013601
[ INFO] [1502542751.858843499]: expired 0.002036, real 0.017106, diff 0.015070
[ INFO] [1502542751.860270164]: expired 0.001401, real 0.017961, diff 0.016560
[ INFO] [1502542751.877377358]: expired 0.000917, real 0.034411, diff 0.033494
[ INFO] [1502542751.879162825]: expired 0.002981, real 0.030820, diff 0.027839
[ INFO] [1502542751.930662964]: expired 0.000388, real 0.005250, diff 0.004862
[ INFO] [1502542752.028550150]: expired 0.000010, real 0.003089, diff 0.003079
[ INFO] [1502542752.050085139]: expired 0.003665, real 0.008798, diff 0.005134
[ INFO] [1502542752.051358398]: expired 0.003556, real 0.009937, diff 0.006382
[ INFO] [1502542752.052558492]: expired 0.003463, real 0.011059, diff 0.007595
[ INFO] [1502542752.054006279]: expired 0.002937, real 0.011867, diff 0.008931
[ INFO] [1502542752.055447886]: expired 0.000879, real 0.011298, diff 0.010419
[ INFO] [1502542752.060083916]: expired 0.000015, real 0.011206, diff 0.011191
[ INFO] [1502542752.132625697]: expired 0.000357, real 0.007029, diff 0.006673
[ INFO] [1502542752.236591848]: expired 0.000605, real 0.011162, diff 0.010557
[ INFO] [1502542752.254498218]: expired 0.003123, real 0.013214, diff 0.010091
[ INFO] [1502542752.255663705]: expired 0.002982, real 0.014244, diff 0.011262
[ INFO] [1502542752.256927870]: expired 0.002853, real 0.015364, diff 0.012512
[ INFO] [1502542752.258101913]: expired 0.002616, real 0.016313, diff 0.013696
[ INFO] [1502542752.259481225]: expired 0.001527, real 0.016569, diff 0.015042
[ INFO] [1502542752.261095417]: expired 0.002467, real 0.011868, diff 0.009402
[ INFO] [1502542752.345381996]: expired 0.010527, real 0.019968, diff 0.009441
[ INFO] [1502542752.346644440]: expired 0.002424, real 0.005249, diff 0.002825
[ INFO] [1502542752.347965664]: expired 0.002389, real 0.006455, diff 0.004065
[ INFO] [1502542752.350269660]: expired 0.002329, real 0.008717, diff 0.006388
[ INFO] [1502542752.352199583]: expired 0.001944, real 0.010266, diff 0.008322
[ INFO] [1502542752.353577292]: expired 0.001488, real 0.011188, diff 0.009700
[ INFO] [1502542752.365322771]: expired 0.010630, real 0.020816, diff 0.010186
[ INFO] [1502542752.437751206]: expired 0.010925, real 0.012206, diff 0.001281
[ INFO] [1502542752.449800691]: expired 0.001124, real 0.008503, diff 0.007379
[ INFO] [1502542752.461325956]: expired 0.002531, real 0.011751, diff 0.009220
[ INFO] [1502542752.535055100]: expired 0.002470, real 0.009466, diff 0.006996
[ INFO] [1502542752.638692151]: expired 0.007845, real 0.013047, diff 0.005202
[ INFO] [1502542752.651159780]: expired 0.003241, real 0.009861, diff 0.006620
[ INFO] [1502542752.652520336]: expired 0.003142, real 0.011091, diff 0.007948
[ INFO] [1502542752.653747137]: expired 0.003118, real 0.012294, diff 0.009175
[ INFO] [1502542752.655073042]: expired 0.003057, real 0.013541, diff 0.010484
[ INFO] [1502542752.656306485]: expired 0.002960, real 0.014705, diff 0.011745
[ INFO] [1502542752.657510904]: expired 0.002811, real 0.015739, diff 0.012928
[ INFO] [1502542752.658667355]: expired 0.002458, real 0.016548, diff 0.014090
[ INFO] [1502542752.659774684]: expired 0.001552, real 0.016740, diff 0.015187
[ INFO] [1502542752.667593517]: expired 0.000087, real 0.022915, diff 0.022828
[ INFO] [1502542752.678309054]: expired 0.000012, real 0.028359, diff 0.028347
[ INFO] [1502542752.750949658]: expired 0.015274, real 0.025540, diff 0.010266
[ INFO] [1502542752.843120589]: expired 0.010539, real 0.017710, diff 0.007171
[ INFO] [1502542752.854678124]: expired 0.003276, real 0.013388, diff 0.010111
[ INFO] [1502542752.855997270]: expired 0.003086, real 0.014525, diff 0.011440
[ INFO] [1502542752.857179653]: expired 0.002904, real 0.015521, diff 0.012616
[ INFO] [1502542752.858493180]: expired 0.002854, real 0.016781, diff 0.013927
[ INFO] [1502542752.859773561]: expired 0.002089, real 0.017286, diff 0.015197
[ INFO] [1502542752.871310734]: expired 0.008131, real 0.018231, diff 0.010100
[ INFO] [1502542752.944668168]: expired 0.011038, real 0.018987, diff 0.007949
[ INFO] [1502542752.957339728]: expired 0.005078, real 0.015529, diff 0.010451
[ INFO] [1502542752.959813960]: expired 0.001779, real 0.015073, diff 0.013294
[ INFO] [1502542753.034413199]: expired 0.003210, real 0.008851, diff 0.005641
[ INFO] [1502542753.046444620]: expired 0.003235, real 0.005140, diff 0.001905
[ INFO] [1502542753.047769135]: expired 0.003094, real 0.006314, diff 0.003220
[ INFO] [1502542753.049049957]: expired 0.003002, real 0.007510, diff 0.004508
[ INFO] [1502542753.051604634]: expired 0.002969, real 0.009995, diff 0.007026
[ INFO] [1502542753.054975366]: expired 0.002674, real 0.013087, diff 0.010413
[ INFO] [1502542753.063601891]: expired 0.002573, real 0.021616, diff 0.019043
[ INFO] [1502542753.065871053]: expired 0.001389, real 0.022695, diff 0.021307
[ INFO] [1502542753.085028412]: expired 0.012560, real 0.031526, diff 0.018967
[ INFO] [1502542753.127085973]: expired 0.000011, real 0.001668, diff 0.001657
[ INFO] [1502542753.229785368]: expired 0.000013, real 0.004306, diff 0.004293
[ INFO] [1502542753.252093972]: expired 0.000008, real 0.010785, diff 0.010777
[ INFO] [1502542753.254750253]: expired 0.000003, real 0.013037, diff 0.013034
[ INFO] [1502542753.259457162]: expired 0.002988, real 0.017939, diff 0.014951
[ INFO] [1502542753.261224242]: expired 0.002314, real 0.019015, diff 0.016700
[ INFO] [1502542753.263483492]: expired 0.003562, real 0.018502, diff 0.014940
[ INFO] [1502542753.276123548]: expired 0.000440, real 0.022247, diff 0.021807
[ INFO] [1502542753.331329721]: expired 0.000029, real 0.005874, diff 0.005845
[ INFO] [1502542753.353832736]: expired 0.003026, real 0.012330, diff 0.009304
[ INFO] [1502542753.357188203]: expired 0.001951, real 0.013792, diff 0.011841
[ INFO] [1502542753.429592927]: expired 0.000826, real 0.004165, diff 0.003339
[ INFO] [1502542753.453221298]: expired 0.002367, real 0.011921, diff 0.009554
[ INFO] [1502542753.455434608]: expired 0.002228, real 0.013954, diff 0.011726
[ INFO] [1502542753.458632923]: expired 0.000366, real 0.015165, diff 0.014799
[ INFO] [1502542753.472479240]: expired 0.004352, real 0.018122, diff 0.013770
[ INFO] [1502542753.536509762]: expired 0.000986, real 0.011056, diff 0.010070
[ INFO] [1502542753.548871900]: expired 0.000046, real 0.007422, diff 0.007377
[ INFO] [1502542753.551239190]: expired 0.000011, real 0.009504, diff 0.009493
[ INFO] [1502542753.555198521]: expired 0.000025, real 0.013151, diff 0.013127
[ INFO] [1502542753.567933845]: expired 0.000286, real 0.022742, diff 0.022457
[ INFO] [1502542753.635031658]: expired 0.001146, real 0.009612, diff 0.008467
[ INFO] [1502542753.647773185]: expired 0.003229, real 0.006478, diff 0.003249
[ INFO] [1502542753.660379391]: expired 0.001856, real 0.005433, diff 0.003577
[ INFO] [1502542753.735454226]: expired 0.001265, real 0.010029, diff 0.008764
[ INFO] [1502542753.747878871]: expired 0.002954, real 0.006164, diff 0.003211
[ INFO] [1502542753.750818241]: expired 0.002491, real 0.008584, diff 0.006093
[ INFO] [1502542753.827872254]: expired 0.001391, real 0.002448, diff 0.001057
[ INFO] [1502542753.846163370]: expired 0.003264, real 0.004864, diff 0.001600
[ INFO] [1502542753.848932570]: expired 0.003186, real 0.007508, diff 0.004323
[ INFO] [1502542753.851381222]: expired 0.003163, real 0.009917, diff 0.006755
[ INFO] [1502542753.855404546]: expired 0.003136, real 0.013898, diff 0.010761
[ INFO] [1502542753.857887417]: expired 0.003110, real 0.016348, diff 0.013237
[ INFO] [1502542753.868333822]: expired 0.003048, real 0.026736, diff 0.023688
[ INFO] [1502542753.879836373]: expired 0.002971, real 0.038153, diff 0.035182
[ INFO] [1502542753.895244889]: expired 0.002874, real 0.053460, diff 0.050586
[ INFO] [1502542753.919360957]: expired 0.002716, real 0.077410, diff 0.074694
[ INFO] [1502542753.933169649]: expired 0.002350, real 0.090818, diff 0.088467
[ WARN] [1502542753.977203922]: expired 0.001971, real 0.134395, diff 0.132424
[ WARN] [1502542753.982966317]: expired 0.001207, real 0.139471, diff 0.138265
[ WARN] [1502542754.022249746]: expired 0.003520, real 0.175308, diff 0.171787
[ WARN] [1502542754.035299846]: expired 0.002663, real 0.179780, diff 0.177117
[ WARN] [1502542754.065188591]: expired 0.000020, real 0.139769, diff 0.139749
[ WARN] [1502542754.067392725]: expired 0.000012, real 0.125506, diff 0.125494
[ INFO] [1502542754.126807529]: expired 0.003249, real 0.085498, diff 0.082249
[ INFO] [1502542754.128775625]: expired 0.000946, real 0.073213, diff 0.072266
[ WARN] [1502542754.130674986]: expired 0.068550, real 0.105283, diff 0.036733
[ INFO] [1502542754.173096050]: expired 0.027278, real 0.047479, diff 0.020201
[ INFO] [1502542754.175908544]: expired 0.011296, real 0.034312, diff 0.023015
[ INFO] [1502542754.222057472]: expired 0.007125, real 0.076425, diff 0.069300
[ INFO] [1502542754.248817026]: expired 0.007699, real 0.023380, diff 0.015680
[ INFO] [1502542754.251154194]: expired 0.003384, real 0.009869, diff 0.006485
[ INFO] [1502542754.262450782]: expired 0.003356, real 0.020982, diff 0.017626
[ INFO] [1502542754.292494138]: expired 0.001213, real 0.035080, diff 0.033866
[ INFO] [1502542754.310210516]: expired 0.000461, real 0.054140, diff 0.053678
[ INFO] [1502542754.330000062]: expired 0.002109, real 0.004576, diff 0.002467
[ INFO] [1502542754.343279695]: expired 0.000014, real 0.001759, diff 0.001744
[ INFO] [1502542754.357506491]: expired 0.000008, real 0.014667, diff 0.014659
[ INFO] [1502542754.434414318]: expired 0.002248, real 0.008978, diff 0.006730
[ INFO] [1502542754.446946449]: expired 0.003256, real 0.005627, diff 0.002371
[ INFO] [1502542754.449749996]: expired 0.003161, real 0.008264, diff 0.005103
[ INFO] [1502542754.452161883]: expired 0.003072, real 0.010635, diff 0.007564
[ INFO] [1502542754.454732421]: expired 0.003046, real 0.013168, diff 0.010122
[ INFO] [1502542754.471662191]: expired 0.002981, real 0.030016, diff 0.027035
[ INFO] [1502542754.482978803]: expired 0.002723, real 0.040908, diff 0.038184
[ INFO] [1502542754.512825411]: expired 0.002482, real 0.070571, diff 0.068090
[ INFO] [1502542754.528124241]: expired 0.002222, real 0.085658, diff 0.083436
[ WARN] [1502542754.549642151]: expired 0.001262, real 0.103784, diff 0.102522
[ INFO] [1502542754.558970416]: expired 0.003122, real 0.081399, diff 0.078277
[ INFO] [1502542754.574136380]: expired 0.002521, real 0.048723, diff 0.046202
[ INFO] [1502542754.627366113]: expired 0.000048, real 0.001813, diff 0.001766
[ INFO] [1502542754.644656455]: expired 0.003232, real 0.003360, diff 0.000128
[ INFO] [1502542754.646475384]: expired 0.003094, real 0.005015, diff 0.001920
[ INFO] [1502542754.648169356]: expired 0.002968, real 0.006598, diff 0.003630
[ INFO] [1502542754.714540983]: expired 0.002569, real 0.072517, diff 0.069948
[ INFO] [1502542754.717325792]: expired 0.000805, real 0.073545, diff 0.072740
[ INFO] [1502542754.751404125]: expired 0.036419, real 0.073237, diff 0.036818
[ INFO] [1502542754.754502920]: expired 0.000037, real 0.029060, diff 0.029023
[ INFO] [1502542754.784009094]: expired 0.002183, real 0.042562, diff 0.040379
[ INFO] [1502542754.807641433]: expired 0.005029, real 0.061542, diff 0.056513
[ INFO] [1502542754.838661110]: expired 0.003162, real 0.013205, diff 0.010043
[ INFO] [1502542754.851925003]: expired 0.000496, real 0.010627, diff 0.010130
[ INFO] [1502542754.855540156]: expired 0.000341, real 0.013858, diff 0.013517
[ INFO] [1502542754.884376979]: expired 0.000162, real 0.042668, diff 0.042506
[ INFO] [1502542754.887169048]: expired 0.000012, real 0.045305, diff 0.045293
[ INFO] [1502542754.927202017]: expired 0.004734, real 0.084219, diff 0.079485
[ INFO] [1502542754.955928332]: expired 0.006496, real 0.077400, diff 0.070904
[ INFO] [1502542754.972894703]: expired 0.003098, real 0.047295, diff 0.044197
[ INFO] [1502542755.035651427]: expired 0.000202, real 0.010229, diff 0.010028
[ INFO] [1502542755.057071684]: expired 0.005616, real 0.015753, diff 0.010137
[ INFO] [1502542755.060681156]: expired 0.005500, real 0.019184, diff 0.013684
[ INFO] [1502542755.064202964]: expired 0.005475, real 0.022730, diff 0.017255
[ INFO] [1502542755.067276323]: expired 0.005415, real 0.025752, diff 0.020337
[ INFO] [1502542755.086276119]: expired 0.005214, real 0.044528, diff 0.039314
[ INFO] [1502542755.099646227]: expired 0.005169, real 0.057845, diff 0.052676
[ INFO] [1502542755.130084485]: expired 0.004456, real 0.087551, diff 0.083096
[ WARN] [1502542755.149354749]: expired 0.003045, real 0.105168, diff 0.102123
[ WARN] [1502542755.165328605]: expired 0.000627, real 0.118968, diff 0.118341
[ WARN] [1502542755.194568360]: expired 0.001254, real 0.115255, diff 0.114001
[ INFO] [1502542755.214380995]: expired 0.004598, real 0.088731, diff 0.084133
[ INFO] [1502542755.236485856]: expired 0.007389, real 0.083473, diff 0.076084
[ WARN] [1502542755.242851438]: expired 0.006863, real 0.100602, diff 0.093738
[ INFO] [1502542755.296604366]: expired 0.000015, real 0.071173, diff 0.071158
[ INFO] [1502542755.298627179]: expired 0.019550, real 0.057343, diff 0.037793
[ INFO] [1502542755.344602443]: expired 0.029623, real 0.046721, diff 0.017098
[ INFO] [1502542755.346713672]: expired 0.001918, real 0.021293, diff 0.019375
[ INFO] [1502542755.392189633]: expired 0.033042, real 0.050745, diff 0.017703
[ INFO] [1502542755.394362169]: expired 0.033009, real 0.052700, diff 0.019692
[ INFO] [1502542755.428022228]: expired 0.032879, real 0.086390, diff 0.053512
[ WARN] [1502542755.454008791]: expired 0.032567, real 0.111929, diff 0.079362
[ WARN] [1502542755.456371631]: expired 0.031466, real 0.113078, diff 0.081612
[ WARN] [1502542755.480293321]: expired 0.027930, real 0.133484, diff 0.105554
[ INFO] [1502542755.509419755]: expired 0.000020, real 0.083772, diff 0.083752
[ INFO] [1502542755.511898194]: expired 0.003093, real 0.070591, diff 0.067498
[ WARN] [1502542755.552945667]: expired 0.002968, real 0.111304, diff 0.108336
[ WARN] [1502542755.555666031]: expired 0.002841, real 0.113859, diff 0.111017
[ WARN] [1502542755.584035677]: expired 0.002386, real 0.141792, diff 0.139406
[ WARN] [1502542755.586086537]: expired 0.000332, real 0.141970, diff 0.141638
[ INFO] [1502542755.588266563]: expired 0.000020, real 0.086458, diff 0.086438
[ WARN] [1502542755.644669921]: expired 0.012149, real 0.119234, diff 0.107085
[ INFO] [1502542755.646509629]: expired 0.003232, real 0.005218, diff 0.001986
[ INFO] [1502542755.648174070]: expired 0.003125, real 0.006765, diff 0.003639
[ INFO] [1502542755.680908813]: expired 0.003038, real 0.039349, diff 0.036312
[ INFO] [1502542755.682643507]: expired 0.001971, real 0.040039, diff 0.038068
[ WARN] [1502542755.736565879]: expired 0.045445, real 0.111141, diff 0.065696
[ INFO] [1502542755.738715675]: expired 0.023948, real 0.091713, diff 0.067765
[ INFO] [1502542755.752224345]: expired 0.006078, real 0.049645, diff 0.043568
[ INFO] [1502542755.790864371]: expired 0.013420, real 0.065437, diff 0.052017
[ INFO] [1502542755.833447900]: expired 0.003205, real 0.008026, diff 0.004821
[ INFO] [1502542755.845590994]: expired 0.003240, real 0.004292, diff 0.001052
[ INFO] [1502542755.847458762]: expired 0.003100, real 0.005993, diff 0.002893
[ INFO] [1502542755.850883473]: expired 0.003074, real 0.009362, diff 0.006288
[ INFO] [1502542755.853205807]: expired 0.003015, real 0.011648, diff 0.008633
[ INFO] [1502542755.854966345]: expired 0.002900, real 0.013325, diff 0.010424
[ INFO] [1502542755.901077883]: expired 0.002691, real 0.059129, diff 0.056438
[ INFO] [1502542755.907545814]: expired 0.002272, real 0.065208, diff 0.062935
[ INFO] [1502542755.939130891]: expired 0.001410, real 0.095900, diff 0.094490
[ INFO] [1502542755.941690725]: expired 0.000292, real 0.097368, diff 0.097075
[ INFO] [1502542755.984121840]: expired 0.004106, real 0.080706, diff 0.076599
[ INFO] [1502542755.987908106]: expired 0.000007, real 0.062482, diff 0.062475
[ INFO] [1502542756.005999897]: expired 0.000232, real 0.064557, diff 0.064325
[ INFO] [1502542756.018410472]: expired 0.001049, real 0.071000, diff 0.069951
[ INFO] [1502542756.072012518]: expired 0.027280, real 0.046346, diff 0.019067
[ INFO] [1502542756.074135499]: expired 0.011438, real 0.032852, diff 0.021414
[ INFO] [1502542756.108574589]: expired 0.000623, real 0.004359, diff 0.003736
[ INFO] [1502542756.130985529]: expired 0.003104, real 0.005563, diff 0.002459
[ INFO] [1502542756.153284593]: expired 0.001393, real 0.011496, diff 0.010103
[ INFO] [1502542756.155310659]: expired 0.001335, real 0.013472, diff 0.012136
[ INFO] [1502542756.229891958]: expired 0.000013, real 0.004316, diff 0.004303
[ INFO] [1502542756.242101476]: expired 0.000126, real 0.000808, diff 0.000683
[ INFO] [1502542756.244117107]: expired 0.000019, real 0.002705, diff 0.002686
[ INFO] [1502542756.246099053]: expired 0.000019, real 0.004642, diff 0.004623
[ INFO] [1502542756.260589108]: expired 0.004688, real 0.019048, diff 0.014360
[ INFO] [1502542756.262706817]: expired 0.004638, real 0.021105, diff 0.016467
[ INFO] [1502542756.292461452]: expired 0.004610, real 0.050504, diff 0.045894
[ INFO] [1502542756.294290156]: expired 0.004462, real 0.052528, diff 0.048066
[ INFO] [1502542756.295926119]: expired 0.004251, real 0.053933, diff 0.049682
[ INFO] [1502542756.333353008]: expired 0.004115, real 0.091198, diff 0.087084
[ INFO] [1502542756.336516695]: expired 0.003558, real 0.093621, diff 0.090063
[ WARN] [1502542756.364756083]: expired 0.001744, real 0.120212, diff 0.118469
[ WARN] [1502542756.371009169]: expired 0.000418, real 0.123195, diff 0.122777
[ INFO] [1502542756.412731023]: expired 0.005882, real 0.088756, diff 0.082875
[ INFO] [1502542756.416272706]: expired 0.004331, real 0.090856, diff 0.086524
[ INFO] [1502542756.439104499]: expired 0.002411, real 0.097563, diff 0.095152
[ WARN] [1502542756.454958202]: expired 0.000608, real 0.111618, diff 0.111010
[ INFO] [1502542756.500746572]: expired 0.013609, real 0.075136, diff 0.061528
[ INFO] [1502542756.505975599]: expired 0.001802, real 0.064676, diff 0.062874
[ INFO] [1502542756.540597308]: expired 0.001996, real 0.015980, diff 0.013983
[ INFO] [1502542756.543366843]: expired 0.001319, real 0.017964, diff 0.016646
[ INFO] [1502542756.558157730]: expired 0.001361, real 0.016722, diff 0.015361
[ INFO] [1502542756.560032035]: expired 0.001257, real 0.018510, diff 0.017253
[ INFO] [1502542756.588153506]: expired 0.000412, real 0.045736, diff 0.045324
[ INFO] [1502542756.592101747]: expired 0.000856, real 0.044115, diff 0.043259
[ INFO] [1502542756.629403547]: expired 0.000032, real 0.003961, diff 0.003928
[ INFO] [1502542756.654434096]: expired 0.000020, real 0.012845, diff 0.012825
[ INFO] [1502542756.657341478]: expired 0.000007, real 0.015751, diff 0.015744
[ INFO] [1502542756.668856844]: expired 0.000015, real 0.024107, diff 0.024091
[ INFO] [1502542756.737081812]: expired 0.000974, real 0.008005, diff 0.007032
[ INFO] [1502542756.739024128]: expired 0.001147, real 0.013615, diff 0.012469
[ INFO] [1502542756.832737659]: expired 0.002571, real 0.007314, diff 0.004743
[ INFO] [1502542756.844995804]: expired 0.003233, real 0.003696, diff 0.000463
[ INFO] [1502542756.846821869]: expired 0.003127, real 0.005405, diff 0.002278
[ INFO] [1502542756.848827791]: expired 0.003070, real 0.007336, diff 0.004266
[ INFO] [1502542756.850773330]: expired 0.003043, real 0.009201, diff 0.006158
[ INFO] [1502542756.852585395]: expired 0.002897, real 0.010914, diff 0.008017
[ INFO] [1502542756.867487617]: expired 0.002635, real 0.025531, diff 0.022896
[ INFO] [1502542756.871459214]: expired 0.001780, real 0.028641, diff 0.026861
[ INFO] [1502542756.897845968]: expired 0.001120, real 0.054154, diff 0.053033
[ INFO] [1502542756.932850705]: expired 0.006429, real 0.084602, diff 0.078173
[ INFO] [1502542756.934974643]: expired 0.003020, real 0.009576, diff 0.006555
[ INFO] [1502542756.949851040]: expired 0.002286, real 0.023650, diff 0.021364
[ INFO] [1502542757.031121337]: expired 0.001675, real 0.005606, diff 0.003931
[ INFO] [1502542757.043478199]: expired 0.000019, real 0.002176, diff 0.002157
[ INFO] [1502542757.045474679]: expired 0.000012, real 0.004030, diff 0.004017
[ INFO] [1502542757.048486024]: expired 0.000004, real 0.006713, diff 0.006710
[ INFO] [1502542757.061133819]: expired 0.008441, real 0.018717, diff 0.010277
[ INFO] [1502542757.063216918]: expired 0.005723, real 0.018249, diff 0.012526
[ INFO] [1502542757.133061513]: expired 0.000042, real 0.007640, diff 0.007598
[ INFO] [1502542757.135023162]: expired 0.000016, real 0.008038, diff 0.008022
[ INFO] [1502542757.147264979]: expired 0.000137, real 0.005828, diff 0.005691
[ INFO] [1502542757.149271645]: expired 0.000017, real 0.007608, diff 0.007591
[ INFO] [1502542757.151418625]: expired 0.000015, real 0.009360, diff 0.009345
[ INFO] [1502542757.163657114]: expired 0.004734, real 0.014809, diff 0.010076
[ INFO] [1502542757.227314135]: expired 0.000018, real 0.001891, diff 0.001874
[ INFO] [1502542757.249822423]: expired 0.003267, real 0.008501, diff 0.005234
[ INFO] [1502542757.251603391]: expired 0.003055, real 0.010065, diff 0.007010
[ INFO] [1502542757.253547921]: expired 0.002888, real 0.011771, diff 0.008882
[ INFO] [1502542757.255508091]: expired 0.002737, real 0.013605, diff 0.010868
[ INFO] [1502542757.257357868]: expired 0.002135, real 0.014886, diff 0.012751
[ INFO] [1502542757.328765933]: expired 0.000097, real 0.003345, diff 0.003247
[ INFO] [1502542757.350698120]: expired 0.001704, real 0.009198, diff 0.007494
[ INFO] [1502542757.352499514]: expired 0.000010, real 0.008838, diff 0.008828
[ INFO] [1502542757.374677814]: expired 0.001720, real 0.007846, diff 0.006126
[ INFO] [1502542757.437262983]: expired 0.001412, real 0.011658, diff 0.010246
[ INFO] [1502542757.449382488]: expired 0.000807, real 0.008091, diff 0.007284
[ INFO] [1502542757.450973345]: expired 0.000689, real 0.009518, diff 0.008829
[ INFO] [1502542757.452195784]: expired 0.000662, real 0.010767, diff 0.010105
[ INFO] [1502542757.453556988]: expired 0.000600, real 0.012049, diff 0.011448
[ INFO] [1502542757.454791991]: expired 0.000348, real 0.013030, diff 0.012682
[ INFO] [1502542757.455959516]: expired 0.000299, real 0.014149, diff 0.013849
[ INFO] [1502542757.457521759]: expired 0.000204, real 0.014590, diff 0.014385
[ INFO] [1502542757.458874546]: expired 0.003340, real 0.013714, diff 0.010374
[ INFO] [1502542757.476696617]: expired 0.008074, real 0.027492, diff 0.019418
[ INFO] [1502542757.532782975]: expired 0.003249, real 0.007213, diff 0.003964
[ INFO] [1502542757.575342324]: expired 0.001246, real 0.003687, diff 0.002442
[ INFO] [1502542757.637984182]: expired 0.002218, real 0.012358, diff 0.010140
[ INFO] [1502542757.649900283]: expired 0.000010, real 0.008583, diff 0.008573
[ INFO] [1502542757.732260071]: expired 0.002065, real 0.006654, diff 0.004589
[ INFO] [1502542757.744036420]: expired 0.000059, real 0.002605, diff 0.002547
[ INFO] [1502542757.755923520]: expired 0.003239, real 0.006106, diff 0.002868
[ INFO] [1502542757.778420880]: expired 0.000256, real 0.005671, diff 0.005416
[ INFO] [1502542757.830974129]: expired 0.003105, real 0.005464, diff 0.002359
[ INFO] [1502542757.842840781]: expired 0.000015, real 0.001555, diff 0.001540
[ INFO] [1502542757.844129867]: expired 0.000005, real 0.002692, diff 0.002688
[ INFO] [1502542757.845629278]: expired 0.000009, real 0.004168, diff 0.004159
[ INFO] [1502542757.847061154]: expired 0.000004, real 0.005481, diff 0.005477
[ INFO] [1502542757.858548295]: expired 0.006785, real 0.016857, diff 0.010072
[ INFO] [1502542757.859721496]: expired 0.006495, real 0.017760, diff 0.011265
[ INFO] [1502542757.861037308]: expired 0.006181, real 0.018740, diff 0.012559
[ INFO] [1502542757.862420616]: expired 0.004732, real 0.018649, diff 0.013917
[ INFO] [1502542757.863838337]: expired 0.003109, real 0.018458, diff 0.015349
[ INFO] [1502542757.932232053]: expired 0.003118, real 0.006816, diff 0.003699
[ INFO] [1502542757.944334419]: expired 0.000183, real 0.002495, diff 0.002312
[ INFO] [1502542757.946532357]: expired 0.000017, real 0.003830, diff 0.003813
[ INFO] [1502542757.978764153]: expired 0.003300, real 0.005201, diff 0.001901
[ INFO] [1502542758.031884357]: expired 0.003124, real 0.006461, diff 0.003337
[ INFO] [1502542758.043989719]: expired 0.000859, real 0.002690, diff 0.001831
[ INFO] [1502542758.045300776]: expired 0.000750, real 0.003879, diff 0.003129
[ INFO] [1502542758.046512214]: expired 0.000658, real 0.005013, diff 0.004355
[ INFO] [1502542758.048048934]: expired 0.000560, real 0.006381, diff 0.005821
[ INFO] [1502542758.049572448]: expired 0.000052, real 0.007445, diff 0.007394
[ INFO] [1502542758.061452575]: expired 0.007897, real 0.018169, diff 0.010271
[ INFO] [1502542758.063865948]: expired 0.001026, real 0.013933, diff 0.012907
[ INFO] [1502542758.127377253]: expired 0.000104, real 0.001971, diff 0.001867
[ INFO] [1502542758.179694955]: expired 0.000044, real 0.005523, diff 0.005479
[ INFO] [1502542758.231656605]: expired 0.000015, real 0.006229, diff 0.006214
[ INFO] [1502542758.243283346]: expired 0.000022, real 0.001998, diff 0.001976
[ INFO] [1502542758.244744055]: expired 0.000704, real 0.003291, diff 0.002587
[ INFO] [1502542758.256233653]: expired 0.000701, real 0.010625, diff 0.009924
[ INFO] [1502542758.331282895]: expired 0.000007, real 0.005872, diff 0.005865
[ INFO] [1502542758.342994612]: expired 0.000012, real 0.001570, diff 0.001558
[ INFO] [1502542758.344364904]: expired 0.000006, real 0.002898, diff 0.002892
[ INFO] [1502542758.345748277]: expired 0.000009, real 0.004013, diff 0.004004
[ INFO] [1502542758.347418177]: expired 0.000008, real 0.005473, diff 0.005465
[ INFO] [1502542758.359110141]: expired 0.004931, real 0.015103, diff 0.010172
[ INFO] [1502542758.360722839]: expired 0.003311, real 0.007623, diff 0.004312
[ INFO] [1502542758.382316400]: expired 0.001539, real 0.007338, diff 0.005799
[ INFO] [1502542758.435244536]: expired 0.001585, real 0.009827, diff 0.008242
[ INFO] [1502542758.446956438]: expired 0.001340, real 0.005656, diff 0.004315
[ INFO] [1502542758.529384631]: expired 0.000990, real 0.003807, diff 0.002817
[ INFO] [1502542758.581869220]: expired 0.000724, real 0.005974, diff 0.005250
[ INFO] [1502542758.633652507]: expired 0.000012, real 0.008237, diff 0.008225
[ INFO] [1502542758.645361001]: expired 0.001494, real 0.004043, diff 0.002549
[ INFO] [1502542758.646772633]: expired 0.001378, real 0.005379, diff 0.004001
[ INFO] [1502542758.648089677]: expired 0.001352, real 0.006631, diff 0.005280
[ INFO] [1502542758.649494686]: expired 0.001291, real 0.007975, diff 0.006684
[ INFO] [1502542758.650784738]: expired 0.001265, real 0.009254, diff 0.007989
[ INFO] [1502542758.652304936]: expired 0.001233, real 0.010611, diff 0.009378
[ INFO] [1502542758.654043633]: expired 0.001049, real 0.012159, diff 0.011110
[ INFO] [1502542758.655847454]: expired 0.000944, real 0.013726, diff 0.012782
[ INFO] [1502542758.686410080]: expired 0.000433, real 0.043768, diff 0.043335
[ INFO] [1502542758.712892712]: expired 0.000141, real 0.064357, diff 0.064215
[ INFO] [1502542758.726152433]: expired 0.000005, real 0.082815, diff 0.082810
[ WARN] [1502542758.750661597]: expired 0.006707, real 0.104586, diff 0.097880
[ INFO] [1502542758.752243254]: expired 0.027956, real 0.098769, diff 0.070814
[ INFO] [1502542758.776548730]: expired 0.000023, real 0.051142, diff 0.051119
[ INFO] [1502542758.778726748]: expired 0.001077, real 0.036825, diff 0.035748
[ INFO] [1502542758.816057923]: expired 0.000967, real 0.002394, diff 0.001427
[ INFO] [1502542758.837993859]: expired 0.002225, real 0.012389, diff 0.010164
[ INFO] [1502542758.849933761]: expired 0.001783, real 0.008616, diff 0.006833
[ INFO] [1502542758.851289608]: expired 0.001701, real 0.009801, diff 0.008100
[ INFO] [1502542758.852620563]: expired 0.001541, real 0.010957, diff 0.009416
[ INFO] [1502542758.853966115]: expired 0.001172, real 0.011940, diff 0.010768
[ INFO] [1502542758.855352136]: expired 0.004394, real 0.011230, diff 0.006835
[ INFO] [1502542758.931442682]: expired 0.000012, real 0.006028, diff 0.006016
[ INFO] [1502542758.953573429]: expired 0.001727, real 0.011932, diff 0.010204
[ INFO] [1502542758.955579675]: expired 0.001556, real 0.013935, diff 0.012379
[ INFO] [1502542758.957105620]: expired 0.000966, real 0.014873, diff 0.013907
[ INFO] [1502542758.969077410]: expired 0.004769, real 0.014972, diff 0.010203
[ INFO] [1502542759.032361143]: expired 0.003977, real 0.007452, diff 0.003476
[ INFO] [1502542759.034710565]: expired 0.003135, real 0.009199, diff 0.006064
[ INFO] [1502542759.046694182]: expired 0.001981, real 0.005416, diff 0.003435
[ INFO] [1502542759.048176567]: expired 0.001832, real 0.006712, diff 0.004879
[ INFO] [1502542759.057364448]: expired 0.000014, real 0.011288, diff 0.011273
[ INFO] [1502542759.129420591]: expired 0.000013, real 0.003994, diff 0.003980
[ INFO] [1502542759.231658937]: expired 0.003132, real 0.006247, diff 0.003116
[ INFO] [1502542759.233189977]: expired 0.002986, real 0.007553, diff 0.004567
[ INFO] [1502542759.244722796]: expired 0.000919, real 0.003441, diff 0.002522
[ INFO] [1502542759.245952280]: expired 0.000803, real 0.004538, diff 0.003736
[ INFO] [1502542759.247415077]: expired 0.000710, real 0.005871, diff 0.005161
[ INFO] [1502542759.248854433]: expired 0.000007, real 0.005536, diff 0.005529
[ INFO] [1502542759.263393379]: expired 0.002280, real 0.009078, diff 0.006799
[       OK ] RoscppTimerCallbacks.multipleSteadyTimeCallbacks (17811 ms)
[----------] 1 test from RoscppTimerCallbacks (17812 ms total)

[----------] Global test environment tear-down
[==========] 1 test from 1 test case ran. (17828 ms total)
[  PASSED  ] 1 test.

@dirk-thomas
Copy link
Member

I would say that is expected behavior on a non-realtime kernel.

Since the patch still changes the API I would think it shouldn't be merged into already released distros. Therefore I would suggest to merge it for ROS M-turtle.

@mikepurvis mikepurvis changed the base branch from lunar-devel to melodic-devel April 21, 2018 21:05
@mikepurvis
Copy link
Member

@ros-pull-request-builder retest this please

@mikepurvis
Copy link
Member

The Debian Stretch failure is known (see #1358), and the other failure looks like flakiness. Thanks for this contribution, @flixr!

@mikepurvis mikepurvis merged commit 24ee9fa into ros:melodic-devel Apr 24, 2018
@flixr flixr deleted the timer_expired branch April 24, 2018 16:41
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants