Re: Audio probles like, slow response in applications that use audio

classic Classic list List threaded Threaded
8 messages Options
Reply | Threaded
Open this post in threaded view
|

Re: Audio probles like, slow response in applications that use audio

Henrique Lengler-2
Hi,

Updating the situation, I already used -stable, and I am using now
-current, and still the problem.
I tried some browsers like (firefox, midori and chromium), and they get
really slow when I am watching a html5 video, and it freezes all the
time if the video is in HD.

Here is almost all the problem
information:http://marc.info/?l=openbsd-misc&m=142385651303855&w=2 

--
Regards

Henrique Lengler

Reply | Threaded
Open this post in threaded view
|

Re: Audio probles like, slow response in applications that use audio

Alexandre Ratchov-2
On Wed, Mar 04, 2015 at 06:59:43PM -0300, Henrique Lengler wrote:

> Hi,
>
> Updating the situation, I already used -stable, and I am using now
> -current, and still the problem.
> I tried some browsers like (firefox, midori and chromium), and they get
> really slow when I am watching a html5 video, and it freezes all the
> time if the video is in HD.
>
> Here is almost all the problem
> information:http://marc.info/?l=openbsd-misc&m=142385651303855&w=2 

Let's first fix system-related audio problems (as programs depend
on it). Once we're sure audio works well, then we can try to debug
browsers which are known to not work well yet in all cases.

mplayer is known to work; it has a small lag (iirc, less than
500ms, depends on the setup) which is somewhat acceptable. Could
you confirm at least this works on -current as expected?

Reply | Threaded
Open this post in threaded view
|

Re: Audio probles like, slow response in applications that use audio

Dmitrij D. Czarkoff-2
In reply to this post by Henrique Lengler-2
Henrique Lengler said:
> I tried some browsers like (firefox, midori and chromium), and they get
> really slow when I am watching a html5 video, and it freezes all the
> time if the video is in HD.

If the performance issue depends on video resolution, most likely you
experience problems with hardware graphics acceleration.

Do other GStreamer-based programs play the same videos fine?  What about
non-Gstreamer software, eg. ffplay from ffmpeg?

--
Dmitrij D. Czarkoff

Reply | Threaded
Open this post in threaded view
|

Re: Audio probles like, slow response in applications that use audio

Henrique Lengler-2
On Thu, Mar 05, 2015 at 03:59:37PM +0100, Dmitrij D. Czarkoff wrote:
Hi, Dimitrij, I am using some software from your port (ratox).

> If the performance issue depends on video resolution, most likely you
> experience problems with hardware graphics acceleration.
To me looks like the audio is causing lag on video, since, the problem
happens with cmus too.

> Do other GStreamer-based programs play the same videos fine?  What about
> non-Gstreamer software, eg. ffplay from ffmpeg?
As I said, ffplay is the only one I found that works well, when using it, I
see no lag, even with HD videos.

On Thu, Mar 05, 2015 at 01:45:57PM +0100, Alexandre Ratchov wrote:
> Let's first fix system-related audio problems (as programs depend
> on it). Once we're sure audio works well, then we can try to debug
> browsers which are known to not work well yet in all cases.
>
> mplayer is known to work; it has a small lag (iirc, less than
> 500ms, depends on the setup) which is somewhat acceptable. Could
> you confirm at least this works on -current as expected?

No, still the same thing. mplayer, cmus and html5 video in any browser
(firefox, chromium, webkitbased), are with lag in my system.
Also please remeber that the audio is synchronized, the lag is when I want
to advance the video.

--
Regards

Henrique Lengler

Reply | Threaded
Open this post in threaded view
|

Re: Audio probles like, slow response in applications that use audio

Alexandre Ratchov-2
On Thu, Mar 05, 2015 at 02:42:11PM -0300, Henrique Lengler wrote:

>
> On Thu, Mar 05, 2015 at 01:45:57PM +0100, Alexandre Ratchov wrote:
> > Let's first fix system-related audio problems (as programs depend
> > on it). Once we're sure audio works well, then we can try to debug
> > browsers which are known to not work well yet in all cases.
> >
> > mplayer is known to work; it has a small lag (iirc, less than
> > 500ms, depends on the setup) which is somewhat acceptable. Could
> > you confirm at least this works on -current as expected?
>
> No, still the same thing. mplayer, cmus and html5 video in any browser
> (firefox, chromium, webkitbased), are with lag in my system.
> Also please remeber that the audio is synchronized, the lag is when I want
> to advance the video.

I still don't 100% understand whether you observe an audio
subsystem bug (>500ms latency), or you just dislike the default
latency.

If you don't like the 200-400ms latency (too conservative imo), you
could lower sndiod buffer size, possibly patch mplayer, cmus or
whatever to use smaller buffers as well, post diffs on ports@ and
if this hurts no MP kernel users we'll change the defaults. This
would improve everybody's setup.

Let me know if you need help for this.

Browsers are a different story. They use a huge amount of code with
complex interaction that makes simple things complicated to debug.
I'd suggest to first make work mplayer, cmus & friends.

Reply | Threaded
Open this post in threaded view
|

Re: Audio probles like, slow response in applications that use audio

Henrique Lengler-2
On Fri, Mar 06, 2015 at 09:06:00AM +0100, Alexandre Ratchov wrote:
> > Also please remeber that the audio is synchronized, the lag is when I want
> > to advance the video.
>
> I still don't 100% understand whether you observe an audio
> subsystem bug (>500ms latency), or you just dislike the default
> latency.

This can't be a feature (right?), since I already use all these apps in
this same computer under linux, and they ran very fast.

To remeber:
The behaviour that mplayer and cmus, are having, is operate with a
delay. Any change in the audio play, like advance in the audio/video, or stop
playing it, takes a time to happen.

For example when I am in these apps and I click pause buttom, it takes a
time like 1~2 seconds to respond. And If I click more than one time, it
lags even more.

> If you don't like the 200-400ms latency (too conservative imo), you
> could lower sndiod buffer size, possibly patch mplayer, cmus or
> whatever to use smaller buffers as well, post diffs on ports@ and
> if this hurts no MP kernel users we'll change the defaults. This
> would improve everybody's setup.

I already changed the buffer, and it didn't solved, as you can see here:
http://marc.info/?l=openbsd-misc&m=142368103115408&w=2
This page have some usefull informations.

About change the application buffers, never tried, but if these apps
worked on Linux, it should work here right, or maybe the OBSD version
have some modification.

> Let me know if you need help for this.
>
> Browsers are a different story. They use a huge amount of code with
> complex interaction that makes simple things complicated to debug.
> I'd suggest to first make work mplayer, cmus & friends.

I totally agree, lets focus on simples tools first.

--
Regards

Henrique Lengler

Reply | Threaded
Open this post in threaded view
|

Re: Audio probles like, slow response in applications that use audio

Alexandre Ratchov-2
On Fri, Mar 06, 2015 at 04:24:53PM -0300, Henrique Lengler wrote:

> On Fri, Mar 06, 2015 at 09:06:00AM +0100, Alexandre Ratchov wrote:
> > > Also please remeber that the audio is synchronized, the lag is when I want
> > > to advance the video.
> >
> > I still don't 100% understand whether you observe an audio
> > subsystem bug (>500ms latency), or you just dislike the default
> > latency.
>
> This can't be a feature (right?), since I already use all these apps in
> this same computer under linux, and they ran very fast.
>
> To remeber:
> The behaviour that mplayer and cmus, are having, is operate with a
> delay. Any change in the audio play, like advance in the audio/video, or stop
> playing it, takes a time to happen.
>
> For example when I am in these apps and I click pause buttom, it takes a
> time like 1~2 seconds to respond. And If I click more than one time, it
> lags even more.

1-2 seconds is a bug. I couldn't reproduce it, unfortunately. On my
box the default setup (same parameters as yours, same device) the
lang is at most 500ms, as expected. IMO 500ms is too much nowadays,
but before questioning it, we must fix your box to not lag 1-2s,
which I consider a bug.

> > If you don't like the 200-400ms latency (too conservative imo), you
> > could lower sndiod buffer size, possibly patch mplayer, cmus or
> > whatever to use smaller buffers as well, post diffs on ports@ and
> > if this hurts no MP kernel users we'll change the defaults. This
> > would improve everybody's setup.
>
> I already changed the buffer, and it didn't solved, as you can see here:
> http://marc.info/?l=openbsd-misc&m=142368103115408&w=2
> This page have some usefull informations.
>
> About change the application buffers, never tried, but if these apps
> worked on Linux, it should work here right, or maybe the OBSD version
> have some modification.

Yes we have modifications. Back around 2008, audio used to be very
unsable on MP systems and sndiod used to run with lower priority.
So using large buffers (around 500ms) was the only way to get
stable audio.

Nowadays, this is not necessary, but buffer sizes are still big
because nobody tryed to reduce them. Maybe it's time now. Properly
written software could probably work with 50ms buffers.

Still I'm talking about 500ms. Not the 1-2s you mentioned, which I
need to understand.

Could you do the following: in one window, kill sndiod and start a
new one as follows:

sudo pkill sndiod
SNDIO_DEBUG=4 sndiod -ddd 2>/tmp/log

in another window:

mplayer /foo/bar.mp3

after few seconds, push the right arrow key to skip forward, wait
few seconds, press q, kill sndiod and send me the /tmp/log file.

When you hit the right arrow key, mplayer is supposed to take 500ms
to react, but on your setup it takes 1-2s, right?

The file is huge, so please send it off-list.

Thanks

-- Alexandre

Reply | Threaded
Open this post in threaded view
|

Re: Audio probles like, slow response in applications that use audio

Henrique Lengler-2
On Fri, Mar 06, 2015 at 09:07:40PM +0100, Alexandre Ratchov wrote:

> Yes we have modifications. Back around 2008, audio used to be very
> unsable on MP systems and sndiod used to run with lower priority.
> So using large buffers (around 500ms) was the only way to get
> stable audio.
>
> Nowadays, this is not necessary, but buffer sizes are still big
> because nobody tryed to reduce them. Maybe it's time now. Properly
> written software could probably work with 50ms buffers.
>
> Still I'm talking about 500ms. Not the 1-2s you mentioned, which I
> need to understand.
>
> Could you do the following: in one window, kill sndiod and start a
> new one as follows:
>
> sudo pkill sndiod
> SNDIO_DEBUG=4 sndiod -ddd 2>/tmp/log
>
> in another window:
>
> mplayer /foo/bar.mp3
>
> after few seconds, push the right arrow key to skip forward, wait
> few seconds, press q, kill sndiod and send me the /tmp/log file.
>
> When you hit the right arrow key, mplayer is supposed to take 500ms
> to react, but on your setup it takes 1-2s, right?
>
> The file is huge, so please send it off-list.

I attached the file
--
Regards

Henrique Lengler
snd0 pst=cfg.default: rec=0:1 play=0:1 vol=23170 dup
listen(/tmp/aucat-1000/aucat0|ini): created
sock(sock|ini): created
sock,rmsg,widl: AUTH message
sio_sun_setpar: 0: trying pars = 48000/16/6
sio_sun_setpar: bpf = (4, 4)
sio_sun_setpar: 0: trying round = 600 -> (576, 576)
sio_sun_setpar: blocksize ok
sio_sun_setpar: 0: trying pars = 48000/16/6
sio_sun_setpar: bpf = (4, 4)
sio_sun_setpar: 0: trying round = 960 -> (960, 960)
sio_sun_setpar: blocksize ok
sock,rmsg,widl: HELLO message
sock,rmsg,widl: hello from <mplayer>, mode = 1, ver 7
sock,rmsg,widl: using snd0 pst=cfg.default, mode = 1
mplayer0: overwritten slot 0
snd0 pst=cfg: device requested
sio(rsnd/0|ini): created
snd0 pst=ini: 48000Hz, s16le, play 0:1, rec 0:1, 9 blocks of 960 frames
mplayer0 vol=127,pst=ini,mmc=off,rmsg,widl: SETPAR message
mplayer0 vol=127,pst=ini,mmc=off,rmsg,widl: playback channels 0:1 -> 0:1
mplayer0 vol=127,pst=ini,mmc=off,rmsg,widl: 44100Hz sample rate, 882 frame blocks
mplayer0 vol=127,pst=ini,mmc=off,rmsg,widl: 11466 frame buffer
mplayer0 vol=127,pst=ini,mmc=off,rmsg,widl: GETPAR message
mplayer0 vol=127,pst=ini,mmc=off,rmsg,widl: GETPAR message
mplayer0 vol=127,pst=ini,mmc=off,rmsg,widl: START message
mplayer0 vol=127,pst=ini,mmc=off: playing s32le -> s16le
mplayer0 vol=127,pst=ini,mmc=off: allocated 11466/19404 fr buffers
mplayer0 vol=127,pst=sta,mmc=off: 44100Hz, s32le, play 0:1, 13 blocks of 882 frames
mplayer0 vol=127,pst=sta,mmc=off,rmsg,widl: building SETVOL message, vol = 127
snd0 pst=ini: device started
snd0 pst=run: started
mplayer0 vol=127,pst=run,mmc=off: attached at -7938, delta = 0
cmap: nch = 2, ostart = 0, onext = 0, istart = 0, inext = 0
dec: s32le, 2 channels
resamp: 882/960
mplayer0 vol=127,pst=run,mmc=off: set weight: 23170/23170
000012083: sio_revents: revents = 0x4, took 1537ns
000035969: sio_revents: revents = 0x4, took 1257ns
000047213: sio_revents: revents = 0x4, took 1257ns
000057410: sio_revents: revents = 0x4, took 1257ns
000067746: sio_revents: revents = 0x4, took 1258ns
000078223: sio_revents: revents = 0x4, took 1187ns
000095893: sio_revents: revents = 0x4, took 1257ns
000106788: sio_revents: revents = 0x4, took 1187ns
000117194: sio_revents: revents = 0x4, took 1187ns
00000849340: clk    +0   +0, wr    +8   +0 rd:    +0   +0
00020857890: clk    +1   +0, wr    +9   +0 rd:    +0   +0
020856284: sio_revents: revents = 0x1, took 4330ns
020903706: sio_revents: revents = 0x0, took 1327ns
020928570: sio_revents: revents = 0x0, took 1327ns
00040880828: clk    +2   +0, wr   +10   +0 rd:    +1   +0
040879291: sio_revents: revents = 0x1, took 5238ns
040912396: sio_revents: revents = 0x0, took 1257ns
040932370: sio_revents: revents = 0x0, took 1258ns
00060857879: clk    +3   +0, wr   +11   +0 rd:    +2   +0
060856343: sio_revents: revents = 0x1, took 5098ns
060889308: sio_revents: revents = 0x0, took 1257ns
060908304: sio_revents: revents = 0x0, took 1258ns
00080882842: clk    +4   +0, wr   +12   +0 rd:    +3   +0
080881515: sio_revents: revents = 0x1, took 3422ns
080911756: sio_revents: revents = 0x0, took 1257ns
080928937: sio_revents: revents = 0x0, took 1257ns
00100857728: clk    +5   +0, wr   +13   +0 rd:    +4   +0
100856401: sio_revents: revents = 0x1, took 3492ns
100886852: sio_revents: revents = 0x0, took 1327ns
100904312: sio_revents: revents = 0x0, took 1327ns
00120890024: clk    +6   +0, wr   +14   +0 rd:    +5   +0
120888697: sio_revents: revents = 0x1, took 3353ns
120918799: sio_revents: revents = 0x0, took 1187ns
120935770: sio_revents: revents = 0x0, took 1257ns
00140857647: clk    +7   +0, wr   +15   +0 rd:    +6   +0
140856250: sio_revents: revents = 0x1, took 4051ns
140888238: sio_revents: revents = 0x0, took 1187ns
140905838: sio_revents: revents = 0x0, took 1257ns
00160902165: clk    +8   +0, wr   +16   +0 rd:    +7   +0
160900908: sio_revents: revents = 0x1, took 3353ns
160931219: sio_revents: revents = 0x0, took 1258ns
160948610: sio_revents: revents = 0x0, took 1257ns
00180857636: clk    +9   +0, wr   +17   +0 rd:    +8   +0
180856309: sio_revents: revents = 0x1, took 3632ns
180887319: sio_revents: revents = 0x0, took 1187ns
180915674: sio_revents: revents = 0x0, took 1327ns
00200909977: clk   +10   +0, wr   +18   +0 rd:    +9   +0
200908300: sio_revents: revents = 0x1, took 5657ns
200942173: sio_revents: revents = 0x0, took 1188ns
208599222: sio_revents: revents = 0x0, took 1537ns
208614587: sio_revents: revents = 0x0, took 1258ns
208627997: sio_revents: revents = 0x0, took 1257ns
208640708: sio_revents: revents = 0x0, took 1187ns
00220858044: clk   +11   +0, wr   +19   +0 rd:   +10   +0
220856507: sio_revents: revents = 0x1, took 5448ns
220890101: sio_revents: revents = 0x0, took 1257ns
238503165: sio_revents: revents = 0x0, took 1257ns
238516714: sio_revents: revents = 0x0, took 1257ns
238529774: sio_revents: revents = 0x0, took 1258ns
238542276: sio_revents: revents = 0x0, took 1257ns
00240921140: clk   +12   +0, wr   +20   +0 rd:   +11   +0
240919673: sio_revents: revents = 0x1, took 5169ns
240953057: sio_revents: revents = 0x0, took 1327ns
00260858522: clk   +13   +0, wr   +21   +0 rd:   +12   +0
260857195: sio_revents: revents = 0x1, took 3282ns
260887296: sio_revents: revents = 0x0, took 1257ns
268596237: sio_revents: revents = 0x0, took 1397ns
268610974: sio_revents: revents = 0x0, took 1257ns
268624034: sio_revents: revents = 0x0, took 1327ns
268636606: sio_revents: revents = 0x0, took 1257ns
268649317: sio_revents: revents = 0x0, took 1327ns
268661818: sio_revents: revents = 0x0, took 1188ns
268674390: sio_revents: revents = 0x0, took 1257ns
268686891: sio_revents: revents = 0x0, took 1257ns
00280929999: clk   +14   +0, wr   +22   +0 rd:   +13   +0
280928392: sio_revents: revents = 0x1, took 5448ns
280961986: sio_revents: revents = 0x0, took 1257ns
298546345: sio_revents: revents = 0x0, took 1606ns
298561920: sio_revents: revents = 0x0, took 1257ns
298575050: sio_revents: revents = 0x0, took 1257ns
298587551: sio_revents: revents = 0x0, took 1258ns
00300858580: clk   +15   +0, wr   +23   +0 rd:   +14   +0
300856974: sio_revents: revents = 0x1, took 5517ns
300890777: sio_revents: revents = 0x0, took 1257ns
00320937460: clk   +16   +0, wr   +24   +0 rd:   +15   +0
320936134: sio_revents: revents = 0x1, took 3492ns
320966584: sio_revents: revents = 0x0, took 1257ns
328550649: sio_revents: revents = 0x0, took 1397ns
328564827: sio_revents: revents = 0x0, took 1257ns
328577818: sio_revents: revents = 0x0, took 1257ns
328590459: sio_revents: revents = 0x0, took 1257ns
328603240: sio_revents: revents = 0x0, took 1257ns
328615671: sio_revents: revents = 0x0, took 1258ns
328628452: sio_revents: revents = 0x0, took 1188ns
328640884: sio_revents: revents = 0x0, took 1257ns
00340858918: clk   +17   +0, wr   +25   +0 rd:   +16   +0
340857382: sio_revents: revents = 0x1, took 5168ns
340890487: sio_revents: revents = 0x0, took 1187ns
358540776: sio_revents: revents = 0x0, took 1397ns
358555163: sio_revents: revents = 0x0, took 1257ns
358568153: sio_revents: revents = 0x0, took 1258ns
358580795: sio_revents: revents = 0x0, took 1257ns
00360945900: clk   +18   +0, wr   +26   +0 rd:   +17   +0
360944433: sio_revents: revents = 0x1, took 5169ns
360977817: sio_revents: revents = 0x0, took 1188ns
00380857650: clk   +19   +0, wr   +27   +0 rd:   +18   +0
380856393: sio_revents: revents = 0x1, took 3282ns
380886355: sio_revents: revents = 0x0, took 1187ns
388549690: sio_revents: revents = 0x0, took 1327ns
388563937: sio_revents: revents = 0x0, took 1257ns
388576928: sio_revents: revents = 0x0, took 1257ns
388589359: sio_revents: revents = 0x0, took 1258ns
388602001: sio_revents: revents = 0x0, took 1327ns
388614502: sio_revents: revents = 0x0, took 1257ns
388627144: sio_revents: revents = 0x0, took 1257ns
388639645: sio_revents: revents = 0x0, took 1257ns
00400953502: clk   +20   +0, wr   +28   +0 rd:   +19   +0
400952035: sio_revents: revents = 0x1, took 5238ns
400985210: sio_revents: revents = 0x0, took 1257ns
418542051: sio_revents: revents = 0x0, took 1467ns
418556648: sio_revents: revents = 0x0, took 1257ns
418569638: sio_revents: revents = 0x0, took 1258ns
418582210: sio_revents: revents = 0x0, took 1257ns
00420858756: clk   +21   +0, wr   +29   +0 rd:   +20   +0
420857290: sio_revents: revents = 0x1, took 6425ns
420892001: sio_revents: revents = 0x0, took 1257ns
00440959427: clk   +22   +0, wr   +30   +0 rd:   +21   +0
440958100: sio_revents: revents = 0x1, took 3352ns
440988271: sio_revents: revents = 0x0, took 1188ns
448580228: sio_revents: revents = 0x0, took 1397ns
448594686: sio_revents: revents = 0x0, took 1257ns
448607746: sio_revents: revents = 0x0, took 1257ns
448620248: sio_revents: revents = 0x0, took 1257ns
448633029: sio_revents: revents = 0x0, took 1257ns
448645530: sio_revents: revents = 0x0, took 1187ns
448658032: sio_revents: revents = 0x0, took 1257ns
448670603: sio_revents: revents = 0x0, took 1257ns
00460858326: clk   +23   +0, wr   +31   +0 rd:   +22   +0
460856720: sio_revents: revents = 0x1, took 5238ns
460890034: sio_revents: revents = 0x0, took 1257ns
478502888: sio_revents: revents = 0x0, took 1327ns
478516298: sio_revents: revents = 0x0, took 1257ns
478529498: sio_revents: revents = 0x0, took 1257ns
478541930: sio_revents: revents = 0x0, took 1257ns
00480964305: clk   +24   +0, wr   +32   +0 rd:   +23   +0
480962768: sio_revents: revents = 0x1, took 5099ns
480995803: sio_revents: revents = 0x0, took 1187ns
00500857616: clk   +25   +0, wr   +33   +0 rd:   +24   +0
500856359: sio_revents: revents = 0x1, took 3283ns
500886531: sio_revents: revents = 0x0, took 1187ns
508591631: sio_revents: revents = 0x0, took 1397ns
508606577: sio_revents: revents = 0x0, took 1257ns
508619567: sio_revents: revents = 0x0, took 1257ns
508632139: sio_revents: revents = 0x0, took 1257ns
508644850: sio_revents: revents = 0x0, took 1257ns
508657351: sio_revents: revents = 0x0, took 1258ns
508669993: sio_revents: revents = 0x0, took 1257ns
508682424: sio_revents: revents = 0x0, took 1258ns
00520968763: clk   +26   +0, wr   +34   +0 rd:   +25   +0
520967227: sio_revents: revents = 0x1, took 5378ns
521001309: sio_revents: revents = 0x0, took 1188ns
538545649: sio_revents: revents = 0x0, took 1397ns
538560037: sio_revents: revents = 0x0, took 1257ns
538574284: sio_revents: revents = 0x0, took 1257ns
538586786: sio_revents: revents = 0x0, took 1257ns
00540859561: clk   +27   +0, wr   +35   +0 rd:   +26   +0
540858024: sio_revents: revents = 0x1, took 5169ns
540891409: sio_revents: revents = 0x0, took 1257ns
00560982022: clk   +28   +0, wr   +36   +0 rd:   +27   +0
560980485: sio_revents: revents = 0x1, took 4820ns
561012822: sio_revents: revents = 0x0, took 1187ns
568548836: sio_revents: revents = 0x0, took 1397ns
568563433: sio_revents: revents = 0x0, took 1257ns
568576493: sio_revents: revents = 0x0, took 1257ns
568588995: sio_revents: revents = 0x0, took 1257ns
568601706: sio_revents: revents = 0x0, took 1187ns
568614138: sio_revents: revents = 0x0, took 1257ns
568626779: sio_revents: revents = 0x0, took 1257ns
568639211: sio_revents: revents = 0x0, took 1257ns
00580863810: clk   +29   +0, wr   +37   +0 rd:   +28   +0
580862274: sio_revents: revents = 0x1, took 5168ns
580895378: sio_revents: revents = 0x0, took 1188ns
598542106: sio_revents: revents = 0x0, took 1396ns
598556353: sio_revents: revents = 0x0, took 1257ns
598569414: sio_revents: revents = 0x0, took 1257ns
598581915: sio_revents: revents = 0x0, took 1257ns
00600994582: clk   +30   +0, wr   +38   +0 rd:   +29   +0
600992976: sio_revents: revents = 0x1, took 5238ns
601026360: sio_revents: revents = 0x0, took 1187ns
00620875462: clk   +31   +0, wr   +39   +0 rd:   +30   +0
620874135: sio_revents: revents = 0x1, took 3423ns
620904446: sio_revents: revents = 0x0, took 1188ns
628586150: sio_revents: revents = 0x0, took 1396ns
628600467: sio_revents: revents = 0x0, took 1257ns
628613457: sio_revents: revents = 0x0, took 1188ns
628625959: sio_revents: revents = 0x0, took 1257ns
628638600: sio_revents: revents = 0x0, took 1258ns
628651102: sio_revents: revents = 0x0, took 1257ns
628663743: sio_revents: revents = 0x0, took 1257ns
628676175: sio_revents: revents = 0x0, took 1257ns
00640858450: clk   +32   +0, wr   +40   +0 rd:   +31   +0
640856914: sio_revents: revents = 0x1, took 5168ns
640891346: sio_revents: revents = 0x0, took 1187ns
658503292: sio_revents: revents = 0x0, took 1327ns
658516701: sio_revents: revents = 0x0, took 1258ns
658529622: sio_revents: revents = 0x0, took 1257ns
658542194: sio_revents: revents = 0x0, took 1257ns
00660881178: clk   +33   +0, wr   +41   +0 rd:   +32   +0
660879642: sio_revents: revents = 0x1, took 5028ns
660912746: sio_revents: revents = 0x0, took 1258ns
00680858788: clk   +34   +0, wr   +42   +0 rd:   +33   +0
680857462: sio_revents: revents = 0x1, took 3352ns
680887493: sio_revents: revents = 0x0, took 1187ns
688581768: sio_revents: revents = 0x0, took 1397ns
688596295: sio_revents: revents = 0x0, took 1257ns
688609145: sio_revents: revents = 0x0, took 1258ns
688621717: sio_revents: revents = 0x0, took 1257ns
688634358: sio_revents: revents = 0x0, took 1257ns
688646930: sio_revents: revents = 0x0, took 1187ns
688659501: sio_revents: revents = 0x0, took 1327ns
688671933: sio_revents: revents = 0x0, took 1257ns
00700887523: clk   +35   +0, wr   +43   +0 rd:   +34   +0
700885916: sio_revents: revents = 0x1, took 5448ns
700919231: sio_revents: revents = 0x0, took 1187ns
718543678: sio_revents: revents = 0x0, took 1537ns
718558904: sio_revents: revents = 0x0, took 1257ns
718571894: sio_revents: revents = 0x0, took 1258ns
718584396: sio_revents: revents = 0x0, took 1257ns
00720859825: clk   +36   +0, wr   +44   +0 rd:   +35   +0
720858288: sio_revents: revents = 0x1, took 5308ns
720891882: sio_revents: revents = 0x0, took 1257ns
00740891981: clk   +37   +0, wr   +45   +0 rd:   +36   +0
740890654: sio_revents: revents = 0x1, took 3353ns
740920616: sio_revents: revents = 0x0, took 1257ns
748550706: sio_revents: revents = 0x0, took 1328ns
748565024: sio_revents: revents = 0x0, took 1257ns
748578084: sio_revents: revents = 0x0, took 1257ns
748590586: sio_revents: revents = 0x0, took 1327ns
748603507: sio_revents: revents = 0x0, took 1257ns
748615938: sio_revents: revents = 0x0, took 1257ns
748628580: sio_revents: revents = 0x0, took 1257ns
748641081: sio_revents: revents = 0x0, took 1257ns
00760858557: clk   +38   +0, wr   +46   +0 rd:   +37   +0
760857020: sio_revents: revents = 0x1, took 5238ns
760890334: sio_revents: revents = 0x0, took 1188ns
778541811: sio_revents: revents = 0x0, took 1397ns
778556268: sio_revents: revents = 0x0, took 1327ns
778569189: sio_revents: revents = 0x0, took 1257ns
778581690: sio_revents: revents = 0x0, took 1257ns
00780892878: clk   +39   +0, wr   +47   +0 rd:   +38   +0
780891342: sio_revents: revents = 0x1, took 5168ns
780924586: sio_revents: revents = 0x0, took 1327ns
00800857917: clk   +40   +0, wr   +48   +0 rd:   +39   +0
800856660: sio_revents: revents = 0x1, took 3282ns
800886622: sio_revents: revents = 0x0, took 1257ns
808581175: sio_revents: revents = 0x0, took 1397ns
808640820: sio_revents: revents = 0x0, took 1537ns
808656185: sio_revents: revents = 0x0, took 1257ns
808668896: sio_revents: revents = 0x0, took 1257ns
808681607: sio_revents: revents = 0x0, took 1257ns
808694039: sio_revents: revents = 0x0, took 1257ns
808706680: sio_revents: revents = 0x0, took 1257ns
808719252: sio_revents: revents = 0x0, took 1187ns
00820896359: clk   +41   +0, wr   +49   +0 rd:   +40   +0
820894822: sio_revents: revents = 0x1, took 5378ns
820928276: sio_revents: revents = 0x0, took 1257ns
838504254: sio_revents: revents = 0x0, took 1327ns
838517734: sio_revents: revents = 0x0, took 1187ns
838530724: sio_revents: revents = 0x0, took 1257ns
838543505: sio_revents: revents = 0x0, took 1257ns
00840859791: clk   +42   +0, wr   +50   +0 rd:   +41   +0
840858255: sio_revents: revents = 0x1, took 5098ns
840891499: sio_revents: revents = 0x0, took 1257ns
00860899630: clk   +43   +0, wr   +51   +0 rd:   +42   +0
860898164: sio_revents: revents = 0x1, took 4050ns
860929802: sio_revents: revents = 0x0, took 1257ns
868586711: sio_revents: revents = 0x0, took 1467ns
868601238: sio_revents: revents = 0x0, took 1257ns
868614508: sio_revents: revents = 0x0, took 1257ns
868627149: sio_revents: revents = 0x0, took 1257ns
868639860: sio_revents: revents = 0x0, took 1257ns
868668705: sio_revents: revents = 0x0, took 1257ns
868681486: sio_revents: revents = 0x0, took 1257ns
868694057: sio_revents: revents = 0x0, took 1257ns
00880858802: clk   +44   +0, wr   +52   +0 rd:   +43   +0
880857266: sio_revents: revents = 0x1, took 5378ns
880890650: sio_revents: revents = 0x0, took 1187ns
898546457: sio_revents: revents = 0x0, took 1466ns
898561403: sio_revents: revents = 0x0, took 1257ns
898574393: sio_revents: revents = 0x0, took 1257ns
898586965: sio_revents: revents = 0x0, took 1257ns
00900899549: clk   +45   +0, wr   +53   +0 rd:   +44   +0
900898013: sio_revents: revents = 0x1, took 5238ns
900931467: sio_revents: revents = 0x0, took 1327ns
00920858372: clk   +46   +0, wr   +54   +0 rd:   +45   +0
920857045: sio_revents: revents = 0x1, took 3562ns
920887636: sio_revents: revents = 0x0, took 1187ns
928553135: sio_revents: revents = 0x0, took 1328ns
928638272: sio_revents: revents = 0x0, took 1537ns
928662717: sio_revents: revents = 0x0, took 1257ns
928817485: sio_revents: revents = 0x0, took 1606ns
928907790: sio_revents: revents = 0x0, took 1746ns
928999282: sio_revents: revents = 0x0, took 1466ns
929090494: sio_revents: revents = 0x0, took 1537ns
929115428: sio_revents: revents = 0x0, took 1397ns
00940902960: clk   +47   +0, wr   +55   +0 rd:   +46   +0
940901354: sio_revents: revents = 0x1, took 5727ns
940935716: sio_revents: revents = 0x0, took 1257ns
958545008: sio_revents: revents = 0x0, took 1467ns
958559675: sio_revents: revents = 0x0, took 1257ns
958572875: sio_revents: revents = 0x0, took 1257ns
958585446: sio_revents: revents = 0x0, took 1188ns
00960859269: clk   +48   +0, wr   +56   +0 rd:   +47   +0
960857662: sio_revents: revents = 0x1, took 5518ns
960891396: sio_revents: revents = 0x0, took 1257ns
00980906581: clk   +49   +0, wr   +57   +0 rd:   +48   +0
980905254: sio_revents: revents = 0x1, took 3282ns
980935286: sio_revents: revents = 0x0, took 1257ns
988549522: sio_revents: revents = 0x0, took 1397ns
988564119: sio_revents: revents = 0x0, took 1257ns
988580182: sio_revents: revents = 0x0, took 1257ns
988592893: sio_revents: revents = 0x0, took 1258ns
988605674: sio_revents: revents = 0x0, took 1258ns
988618176: sio_revents: revents = 0x0, took 1257ns
988630957: sio_revents: revents = 0x0, took 1257ns
988643319: sio_revents: revents = 0x0, took 1257ns
01000858629: clk   +50   +0, wr   +58   +0 rd:   +49   +0
1000857093: sio_revents: revents = 0x1, took 5377ns
1000890407: sio_revents: revents = 0x0, took 1187ns
1018545585: sio_revents: revents = 0x0, took 1467ns
1018560182: sio_revents: revents = 0x0, took 1257ns
1018573312: sio_revents: revents = 0x0, took 1257ns
1018585814: sio_revents: revents = 0x0, took 1257ns
01020914671: clk   +51   +0, wr   +59   +0 rd:   +50   +0
1020913135: sio_revents: revents = 0x1, took 5308ns
1020946589: sio_revents: revents = 0x0, took 1257ns
01040858409: clk   +52   +0, wr   +60   +0 rd:   +51   +0
1040857081: sio_revents: revents = 0x1, took 3493ns
1040887532: sio_revents: revents = 0x0, took 1257ns
1048592493: sio_revents: revents = 0x0, took 1396ns
1048607020: sio_revents: revents = 0x0, took 1257ns
1048620150: sio_revents: revents = 0x0, took 1257ns
1048632721: sio_revents: revents = 0x0, took 1257ns
1048645432: sio_revents: revents = 0x0, took 1327ns
1048658074: sio_revents: revents = 0x0, took 1187ns
1048670715: sio_revents: revents = 0x0, took 1257ns
1048683216: sio_revents: revents = 0x0, took 1258ns
01060917104: clk   +53   +0, wr   +61   +0 rd:   +52   +0
1060915568: sio_revents: revents = 0x1, took 5308ns
1060948813: sio_revents: revents = 0x0, took 1326ns
1078507330: sio_revents: revents = 0x0, took 1537ns
1078522486: sio_revents: revents = 0x0, took 1257ns
1078535616: sio_revents: revents = 0x0, took 1257ns
1078548117: sio_revents: revents = 0x0, took 1258ns
01080859305: clk   +54   +0, wr   +62   +0 rd:   +53   +0
1080857699: sio_revents: revents = 0x1, took 5378ns
1080891363: sio_revents: revents = 0x0, took 1257ns
01100923309: clk   +55   +0, wr   +63   +0 rd:   +54   +0
1100921982: sio_revents: revents = 0x1, took 3353ns
1100953690: sio_revents: revents = 0x0, took 1188ns
1108582523: sio_revents: revents = 0x0, took 1397ns
1108597260: sio_revents: revents = 0x0, took 1257ns
1108610390: sio_revents: revents = 0x0, took 1327ns
1108623101: sio_revents: revents = 0x0, took 1257ns
1108635812: sio_revents: revents = 0x0, took 1257ns
1108648384: sio_revents: revents = 0x0, took 1257ns
1108661095: sio_revents: revents = 0x0, took 1257ns
1108673527: sio_revents: revents = 0x0, took 1257ns
01120858805: clk   +56   +0, wr   +64   +0 rd:   +55   +0
1120857199: sio_revents: revents = 0x1, took 5447ns
1120890443: sio_revents: revents = 0x0, took 1257ns
1138545202: sio_revents: revents = 0x0, took 1467ns
1138559729: sio_revents: revents = 0x0, took 1188ns
1138572790: sio_revents: revents = 0x0, took 1257ns
1138585291: sio_revents: revents = 0x0, took 1257ns
01140918060: clk   +57   +0, wr   +65   +0 rd:   +56   +0
1140916523: sio_revents: revents = 0x1, took 5239ns
1140949977: sio_revents: revents = 0x0, took 1258ns
01160858654: clk   +58   +0, wr   +66   +0 rd:   +57   +0
1160857327: sio_revents: revents = 0x1, took 3283ns
1160887988: sio_revents: revents = 0x0, took 1257ns
1168551253: sio_revents: revents = 0x0, took 1397ns
1168565640: sio_revents: revents = 0x0, took 1257ns
1168578840: sio_revents: revents = 0x0, took 1257ns
1168591411: sio_revents: revents = 0x0, took 1188ns
1168604123: sio_revents: revents = 0x0, took 1257ns
1168616624: sio_revents: revents = 0x0, took 1257ns
1168629265: sio_revents: revents = 0x0, took 1258ns
1168641697: sio_revents: revents = 0x0, took 1257ns
01180911344: clk   +59   +0, wr   +67   +0 rd:   +58   +0
1180909738: sio_revents: revents = 0x1, took 5447ns
1180943890: sio_revents: revents = 0x0, took 1187ns
1198543824: sio_revents: revents = 0x0, took 1396ns
1198558211: sio_revents: revents = 0x0, took 1257ns
1198571271: sio_revents: revents = 0x0, took 1257ns
1198583773: sio_revents: revents = 0x0, took 1257ns
01200860110: clk   +60   +0, wr   +68   +0 rd:   +59   +0
1200858573: sio_revents: revents = 0x1, took 5169ns
1200893005: sio_revents: revents = 0x0, took 1257ns
01220912311: clk   +61   +0, wr   +69   +0 rd:   +60   +0
1220910774: sio_revents: revents = 0x1, took 4121ns
1220942203: sio_revents: revents = 0x0, took 1257ns
1228585633: sio_revents: revents = 0x0, took 1397ns
1228600299: sio_revents: revents = 0x0, took 1258ns
1228613499: sio_revents: revents = 0x0, took 1257ns
1228626071: sio_revents: revents = 0x0, took 1257ns
1228638782: sio_revents: revents = 0x0, took 1257ns
1228651284: sio_revents: revents = 0x0, took 1257ns
1228663925: sio_revents: revents = 0x0, took 1257ns
1228676426: sio_revents: revents = 0x0, took 1258ns
01240859610: clk   +62   +0, wr   +70   +0 rd:   +61   +0
1240858003: sio_revents: revents = 0x1, took 5378ns
1240891388: sio_revents: revents = 0x0, took 1326ns
1258504591: sio_revents: revents = 0x0, took 1257ns
1258517931: sio_revents: revents = 0x0, took 1257ns
1258530921: sio_revents: revents = 0x0, took 1257ns
1258543423: sio_revents: revents = 0x0, took 1257ns
01260916071: clk   +63   +0, wr   +71   +0 rd:   +62   +0
1260914465: sio_revents: revents = 0x1, took 5238ns
1260947779: sio_revents: revents = 0x0, took 1257ns
01280859319: clk   +64   +0, wr   +72   +0 rd:   +63   +0
1280858062: sio_revents: revents = 0x1, took 3283ns
1280888233: sio_revents: revents = 0x0, took 1118ns
1288584603: sio_revents: revents = 0x0, took 1467ns
1288599340: sio_revents: revents = 0x0, took 1257ns
1288612610: sio_revents: revents = 0x0, took 1257ns
1288625321: sio_revents: revents = 0x0, took 1257ns
1288638032: sio_revents: revents = 0x0, took 1187ns
1288650464: sio_revents: revents = 0x0, took 1257ns
1288663175: sio_revents: revents = 0x0, took 1187ns
1288675606: sio_revents: revents = 0x0, took 1258ns
01300909984: clk   +65   +0, wr   +73   +0 rd:   +64   +0
1300908377: sio_revents: revents = 0x1, took 5448ns
1300941761: sio_revents: revents = 0x0, took 1258ns
1318544698: sio_revents: revents = 0x0, took 1397ns
1318559295: sio_revents: revents = 0x0, took 1257ns
1318572285: sio_revents: revents = 0x0, took 1258ns
1318586324: sio_revents: revents = 0x0, took 1257ns
01320860426: clk   +66   +0, wr   +74   +0 rd:   +65   +0
1320858819: sio_revents: revents = 0x1, took 5378ns
1320892483: sio_revents: revents = 0x0, took 1257ns
01340905223: clk   +67   +0, wr   +75   +0 rd:   +66   +0
1340903687: sio_revents: revents = 0x1, took 4958ns
1340936372: sio_revents: revents = 0x0, took 1257ns
1348555079: sio_revents: revents = 0x0, took 1396ns
1348569675: sio_revents: revents = 0x0, took 1258ns
1348582805: sio_revents: revents = 0x0, took 1258ns
1348595377: sio_revents: revents = 0x0, took 1257ns
1348608088: sio_revents: revents = 0x0, took 1257ns
1348620660: sio_revents: revents = 0x0, took 1257ns
1348633161: sio_revents: revents = 0x0, took 1257ns
1348645593: sio_revents: revents = 0x0, took 1257ns
01360859297: clk   +68   +0, wr   +76   +0 rd:   +67   +0
1360857691: sio_revents: revents = 0x1, took 5307ns
1360891284: sio_revents: revents = 0x0, took 1188ns
1378543669: sio_revents: revents = 0x0, took 1327ns
1378557986: sio_revents: revents = 0x0, took 1327ns
1378571046: sio_revents: revents = 0x0, took 1257ns
1378583478: sio_revents: revents = 0x0, took 1257ns
01380896342: clk   +69   +0, wr   +77   +0 rd:   +68   +0
1380894736: sio_revents: revents = 0x1, took 5238ns
1380928190: sio_revents: revents = 0x0, took 1257ns
01400858797: clk   +70   +0, wr   +78   +0 rd:   +69   +0
1400857470: sio_revents: revents = 0x1, took 3282ns
1400887502: sio_revents: revents = 0x0, took 1187ns
1408555167: sio_revents: revents = 0x0, took 1396ns
1408569624: sio_revents: revents = 0x0, took 1257ns
1408582614: sio_revents: revents = 0x0, took 1257ns
1408595116: sio_revents: revents = 0x0, took 1257ns
1408607687: sio_revents: revents = 0x0, took 1257ns
1408620119: sio_revents: revents = 0x0, took 1257ns
1408632690: sio_revents: revents = 0x0, took 1327ns
1408645192: sio_revents: revents = 0x0, took 1257ns
01420893956: clk   +71   +0, wr   +79   +0 rd:   +70   +0
1420892350: sio_revents: revents = 0x1, took 5308ns
1420925595: sio_revents: revents = 0x0, took 1257ns
1438544735: sio_revents: revents = 0x0, took 1396ns
1438559191: sio_revents: revents = 0x0, took 1258ns
1438572252: sio_revents: revents = 0x0, took 1187ns
1438584753: sio_revents: revents = 0x0, took 1257ns
01440859484: clk   +72   +0, wr   +80   +0 rd:   +71   +0
1440857947: sio_revents: revents = 0x1, took 5239ns
1440891401: sio_revents: revents = 0x0, took 1258ns
01460897717: clk   +73   +0, wr   +81   +0 rd:   +72   +0
1460896460: sio_revents: revents = 0x1, took 3282ns
1460926840: sio_revents: revents = 0x0, took 1188ns
1468585286: sio_revents: revents = 0x0, took 1397ns
1468599674: sio_revents: revents = 0x0, took 1257ns
1468612804: sio_revents: revents = 0x0, took 1257ns
1468625375: sio_revents: revents = 0x0, took 1257ns
1468638156: sio_revents: revents = 0x0, took 1257ns
1468650658: sio_revents: revents = 0x0, took 1257ns
1468663369: sio_revents: revents = 0x0, took 1257ns
1468675940: sio_revents: revents = 0x0, took 1257ns
01480859194: clk   +74   +0, wr   +82   +0 rd:   +73   +0
1480857587: sio_revents: revents = 0x1, took 5308ns
1480890901: sio_revents: revents = 0x0, took 1258ns
1498545591: sio_revents: revents = 0x0, took 1327ns
1498559908: sio_revents: revents = 0x0, took 1257ns
1498572899: sio_revents: revents = 0x0, took 1257ns
1498585330: sio_revents: revents = 0x0, took 1327ns
01500904480: clk   +75   +0, wr   +83   +0 rd:   +74   +0
1500902874: sio_revents: revents = 0x1, took 5238ns
1500936328: sio_revents: revents = 0x0, took 1187ns
01520859043: clk   +76   +0, wr   +84   +0 rd:   +75   +0
1520857716: sio_revents: revents = 0x1, took 3631ns
1520888655: sio_revents: revents = 0x0, took 1188ns
1528552409: sio_revents: revents = 0x0, took 1397ns
1528566727: sio_revents: revents = 0x0, took 1257ns
1528579787: sio_revents: revents = 0x0, took 1257ns
1528592289: sio_revents: revents = 0x0, took 1257ns
1528605139: sio_revents: revents = 0x0, took 1258ns
1528617571: sio_revents: revents = 0x0, took 1257ns
1528630213: sio_revents: revents = 0x0, took 1257ns
1528644111: sio_revents: revents = 0x0, took 1257ns
01540910335: clk   +77   +0, wr   +85   +0 rd:   +76   +0
1540908729: sio_revents: revents = 0x1, took 5448ns
1540942113: sio_revents: revents = 0x0, took 1187ns
1558546028: sio_revents: revents = 0x0, took 1327ns
1558560345: sio_revents: revents = 0x0, took 1257ns
1558573336: sio_revents: revents = 0x0, took 1257ns
1558585837: sio_revents: revents = 0x0, took 1257ns
01560860638: clk   +78   +0, wr   +86   +0 rd:   +77   +0
1560859031: sio_revents: revents = 0x1, took 5308ns
1560892555: sio_revents: revents = 0x0, took 1257ns
01580915982: clk   +79   +0, wr   +87   +0 rd:   +78   +0
1580914724: sio_revents: revents = 0x1, took 3283ns
1580944826: sio_revents: revents = 0x0, took 1187ns
1588558853: sio_revents: revents = 0x0, took 1397ns
1588618427: sio_revents: revents = 0x0, took 1467ns
1588633793: sio_revents: revents = 0x0, took 1257ns
1588646504: sio_revents: revents = 0x0, took 1257ns
1588659215: sio_revents: revents = 0x0, took 1257ns
1588671716: sio_revents: revents = 0x0, took 1258ns
1588684358: sio_revents: revents = 0x0, took 1257ns
1588696720: sio_revents: revents = 0x0, took 1257ns
01600860487: clk   +80   +0, wr   +88   +0 rd:   +79   +0
1600858811: sio_revents: revents = 0x1, took 5727ns
1600892824: sio_revents: revents = 0x0, took 1257ns
1618546325: sio_revents: revents = 0x0, took 1467ns
1618560852: sio_revents: revents = 0x0, took 1257ns
1618574052: sio_revents: revents = 0x0, took 1258ns
1618586484: sio_revents: revents = 0x0, took 1257ns
01620926237: clk   +81   +0, wr   +89   +0 rd:   +80   +0
1620924631: sio_revents: revents = 0x1, took 5447ns
1620958364: sio_revents: revents = 0x0, took 1257ns
01640858869: clk   +82   +0, wr   +90   +0 rd:   +81   +0
1640857543: sio_revents: revents = 0x1, took 3422ns
1640887923: sio_revents: revents = 0x0, took 1188ns
1648588274: sio_revents: revents = 0x0, took 1397ns
1648602731: sio_revents: revents = 0x0, took 1257ns
1648615861: sio_revents: revents = 0x0, took 1257ns
1648628433: sio_revents: revents = 0x0, took 1257ns
1648642471: sio_revents: revents = 0x0, took 1257ns
1648655042: sio_revents: revents = 0x0, took 1257ns
1648667684: sio_revents: revents = 0x0, took 1257ns
1648680115: sio_revents: revents = 0x0, took 1258ns
01660931045: clk   +83   +0, wr   +91   +0 rd:   +82   +0
1660929508: sio_revents: revents = 0x1, took 5308ns
1660962753: sio_revents: revents = 0x0, took 1257ns
1678507093: sio_revents: revents = 0x0, took 1257ns
1678520362: sio_revents: revents = 0x0, took 1328ns
1678533423: sio_revents: revents = 0x0, took 1327ns
1678545924: sio_revents: revents = 0x0, took 1258ns
01680860185: clk   +84   +0, wr   +92   +0 rd:   +83   +0
1680858579: sio_revents: revents = 0x1, took 5238ns
1680891963: sio_revents: revents = 0x0, took 1257ns
01700932361: clk   +85   +0, wr   +93   +0 rd:   +84   +0
1700931104: sio_revents: revents = 0x1, took 3212ns
1700961065: sio_revents: revents = 0x0, took 1258ns
1708605543: sio_revents: revents = 0x0, took 1467ns
1708620419: sio_revents: revents = 0x0, took 1257ns
1708633480: sio_revents: revents = 0x0, took 1257ns
1708646121: sio_revents: revents = 0x0, took 1187ns
1708658692: sio_revents: revents = 0x0, took 1257ns
1708671194: sio_revents: revents = 0x0, took 1257ns
1708683835: sio_revents: revents = 0x0, took 1257ns
1708696197: sio_revents: revents = 0x0, took 1257ns
01720859336: clk   +86   +0, wr   +94   +0 rd:   +85   +0
1720857730: sio_revents: revents = 0x1, took 5308ns
1720890974: sio_revents: revents = 0x0, took 1257ns
1738548247: sio_revents: revents = 0x0, took 1537ns
1738563333: sio_revents: revents = 0x0, took 1257ns
1738576463: sio_revents: revents = 0x0, took 1257ns
1738588965: sio_revents: revents = 0x0, took 1257ns
01740931651: clk   +87   +0, wr   +95   +0 rd:   +86   +0
1740930045: sio_revents: revents = 0x1, took 5447ns
1740963778: sio_revents: revents = 0x0, took 1257ns
01760859115: clk   +88   +0, wr   +96   +0 rd:   +87   +0
1760857788: sio_revents: revents = 0x1, took 3283ns
1760888518: sio_revents: revents = 0x0, took 1188ns
1768554158: sio_revents: revents = 0x0, took 1327ns
1768585936: sio_revents: revents = 0x0, took 1257ns
1768599206: sio_revents: revents = 0x0, took 1257ns
1768611777: sio_revents: revents = 0x0, took 1327ns
1768624558: sio_revents: revents = 0x0, took 1187ns
1768637060: sio_revents: revents = 0x0, took 1187ns
1768649841: sio_revents: revents = 0x0, took 1257ns
1768662622: sio_revents: revents = 0x0, took 1187ns
01780931430: clk   +89   +0, wr   +97   +0 rd:   +88   +0
1780929824: sio_revents: revents = 0x1, took 5517ns
1780963208: sio_revents: revents = 0x0, took 1257ns
1798545472: sio_revents: revents = 0x0, took 1327ns
1798559720: sio_revents: revents = 0x0, took 1257ns
1798572780: sio_revents: revents = 0x0, took 1257ns
1798585212: sio_revents: revents = 0x0, took 1187ns
01800860082: clk   +90   +0, wr   +98   +0 rd:   +89   +0
1800858545: sio_revents: revents = 0x1, took 5308ns
1800892069: sio_revents: revents = 0x0, took 1188ns
01820937286: clk   +91   +0, wr   +99   +0 rd:   +90   +0
1820935959: sio_revents: revents = 0x1, took 3282ns
1820966200: sio_revents: revents = 0x0, took 1188ns
1828584557: sio_revents: revents = 0x0, took 1397ns
1828598945: sio_revents: revents = 0x0, took 1257ns
1828611935: sio_revents: revents = 0x0, took 1257ns
1828624437: sio_revents: revents = 0x0, took 1257ns
1828637148: sio_revents: revents = 0x0, took 1257ns
1828649649: sio_revents: revents = 0x0, took 1187ns
1828662151: sio_revents: revents = 0x0, took 1257ns
1828674583: sio_revents: revents = 0x0, took 1257ns
01840860420: clk   +92   +0, wr  +100   +0 rd:   +91   +0
1840858813: sio_revents: revents = 0x1, took 5448ns
1840892128: sio_revents: revents = 0x0, took 1257ns
1858509871: sio_revents: revents = 0x0, took 1537ns
1858524957: sio_revents: revents = 0x0, took 1187ns
1858537877: sio_revents: revents = 0x0, took 1327ns
1858550449: sio_revents: revents = 0x0, took 1257ns
01860945865: clk   +93   +0, wr  +101   +0 rd:   +92   +0
1860944189: sio_revents: revents = 0x1, took 5308ns
1860977783: sio_revents: revents = 0x0, took 1257ns
01880859082: clk   +94   +0, wr  +102   +0 rd:   +93   +0
1880857755: sio_revents: revents = 0x1, took 5657ns
1880890301: sio_revents: revents = 0x0, took 1257ns
1888601267: sio_revents: revents = 0x0, took 1467ns
1888619496: sio_revents: revents = 0x0, took 1257ns
1888632836: sio_revents: revents = 0x0, took 1257ns
1888645337: sio_revents: revents = 0x0, took 1257ns
1888658048: sio_revents: revents = 0x0, took 1188ns
1888670550: sio_revents: revents = 0x0, took 1257ns
1888683261: sio_revents: revents = 0x0, took 1187ns
1888695763: sio_revents: revents = 0x0, took 1257ns
01900955771: clk   +95   +0, wr  +103   +0 rd:   +94   +0
1900954165: sio_revents: revents = 0x1, took 5448ns
1900987549: sio_revents: revents = 0x0, took 1257ns
1918549559: sio_revents: revents = 0x0, took 1397ns
1918564086: sio_revents: revents = 0x0, took 1257ns
1918577146: sio_revents: revents = 0x0, took 1257ns
1918589718: sio_revents: revents = 0x0, took 1257ns
01920860048: clk   +96   +0, wr  +104   +0 rd:   +95   +0
1920858442: sio_revents: revents = 0x1, took 5308ns
1920891966: sio_revents: revents = 0x0, took 1327ns
01940965119: clk   +97   +0, wr  +105   +0 rd:   +96   +0
1940963792: sio_revents: revents = 0x1, took 3282ns
1940993894: sio_revents: revents = 0x0, took 1187ns
1948552397: sio_revents: revents = 0x0, took 1466ns
1948567063: sio_revents: revents = 0x0, took 1257ns
1948580124: sio_revents: revents = 0x0, took 1257ns
1948592695: sio_revents: revents = 0x0, took 1257ns
1948605336: sio_revents: revents = 0x0, took 1257ns
1948617838: sio_revents: revents = 0x0, took 1257ns
1948630479: sio_revents: revents = 0x0, took 1257ns
1948642981: sio_revents: revents = 0x0, took 1257ns
01960859618: clk   +98   +0, wr  +106   +0 rd:   +97   +0
1960858082: sio_revents: revents = 0x1, took 5238ns
1960891186: sio_revents: revents = 0x0, took 1258ns
1978584428: sio_revents: revents = 0x0, took 1467ns
1978599374: sio_revents: revents = 0x0, took 1257ns
1978612504: sio_revents: revents = 0x0, took 1257ns
1978625006: sio_revents: revents = 0x0, took 1257ns
01980978936: clk   +99   +0, wr  +107   +0 rd:   +98   +0
1980977330: sio_revents: revents = 0x1, took 5378ns
1981010924: sio_revents: revents = 0x0, took 1257ns
02000859328: clk  +100   +0, wr  +108   +0 rd:   +99   +0
2000858001: sio_revents: revents = 0x1, took 3352ns
2000888172: sio_revents: revents = 0x0, took 1257ns
2008553532: sio_revents: revents = 0x0, took 1467ns
2008567850: sio_revents: revents = 0x0, took 1257ns
2008580980: sio_revents: revents = 0x0, took 1327ns
2008593482: sio_revents: revents = 0x0, took 1257ns
2008606193: sio_revents: revents = 0x0, took 1257ns
2008618694: sio_revents: revents = 0x0, took 1257ns
2008631266: sio_revents: revents = 0x0, took 1257ns
2008643697: sio_revents: revents = 0x0, took 1257ns
02020988773: clk  +101   +0, wr  +109   +0 rd:  +100   +0
2020987236: sio_revents: revents = 0x1, took 5239ns
2021020481: sio_revents: revents = 0x0, took 1257ns
2038544706: sio_revents: revents = 0x0, took 1397ns
2038558954: sio_revents: revents = 0x0, took 1327ns
2038572154: sio_revents: revents = 0x0, took 1257ns
2038584726: sio_revents: revents = 0x0, took 1257ns
02040868745: clk  +102   +0, wr  +110   +0 rd:  +101   +0
2040867208: sio_revents: revents = 0x1, took 5169ns
2040900593: sio_revents: revents = 0x0, took 1257ns
02060999028: clk  +103   +0, wr  +111   +0 rd:  +102   +0
2060997701: sio_revents: revents = 0x1, took 3423ns
2061027943: sio_revents: revents = 0x0, took 1257ns
2068583233: sio_revents: revents = 0x0, took 1327ns
2068597760: sio_revents: revents = 0x0, took 1257ns
2068610890: sio_revents: revents = 0x0, took 1257ns
2068623392: sio_revents: revents = 0x0, took 1257ns
2068636103: sio_revents: revents = 0x0, took 1257ns
2068648535: sio_revents: revents = 0x0, took 1257ns
2068661246: sio_revents: revents = 0x0, took 1257ns
2068673747: sio_revents: revents = 0x0, took 1258ns
02080882353: clk  +104   +0, wr  +112   +0 rd:  +103   +0
2080880816: sio_revents: revents = 0x1, took 5308ns
2080914270: sio_revents: revents = 0x0, took 1258ns
2098544934: sio_revents: revents = 0x0, took 1397ns
2098560509: sio_revents: revents = 0x0, took 1257ns
2098573639: sio_revents: revents = 0x0, took 1257ns
2098586071: sio_revents: revents = 0x0, took 1257ns
02100861150: clk  +105   +0, wr  +113   +0 rd:  +104   +0
2100859614: sio_revents: revents = 0x1, took 5168ns
2100892858: sio_revents: revents = 0x0, took 1258ns
02120885065: clk  +106   +0, wr  +114   +0 rd:  +105   +0
2120883459: sio_revents: revents = 0x1, took 4889ns
2120915935: sio_revents: revents = 0x0, took 1188ns
2128554407: sio_revents: revents = 0x0, took 1396ns
2128568934: sio_revents: revents = 0x0, took 1327ns
2128582134: sio_revents: revents = 0x0, took 1257ns
2128594635: sio_revents: revents = 0x0, took 1257ns
2128607416: sio_revents: revents = 0x0, took 1257ns
2128619918: sio_revents: revents = 0x0, took 1257ns
2128632559: sio_revents: revents = 0x0, took 1257ns
2128644921: sio_revents: revents = 0x0, took 1257ns
02140859882: clk  +107   +0, wr  +115   +0 rd:  +106   +0
2140858276: sio_revents: revents = 0x1, took 5238ns
2140891450: sio_revents: revents = 0x0, took 1258ns
2158549352: sio_revents: revents = 0x0, took 1397ns
2158563949: sio_revents: revents = 0x0, took 1257ns
2158576940: sio_revents: revents = 0x0, took 1257ns
2158589441: sio_revents: revents = 0x0, took 1257ns
02160899232: clk  +108   +0, wr  +116   +0 rd:  +107   +0
2160897765: sio_revents: revents = 0x1, took 5239ns
2160931848: sio_revents: revents = 0x0, took 1257ns
02180859452: clk  +109   +0, wr  +117   +0 rd:  +108   +0
2180858195: sio_revents: revents = 0x1, took 3282ns
2180888157: sio_revents: revents = 0x0, took 1257ns
2188551561: sio_revents: revents = 0x0, took 1397ns
2188566018: sio_revents: revents = 0x0, took 1258ns
2188578939: sio_revents: revents = 0x0, took 1257ns
2188591441: sio_revents: revents = 0x0, took 1257ns
2188604152: sio_revents: revents = 0x0, took 1257ns
2188616654: sio_revents: revents = 0x0, took 1257ns
2188629295: sio_revents: revents = 0x0, took 1257ns
2188641726: sio_revents: revents = 0x0, took 1258ns
02200915354: clk  +110   +0, wr  +118   +0 rd:  +109   +0
2200913818: sio_revents: revents = 0x1, took 6355ns
2200948249: sio_revents: revents = 0x0, took 1258ns
2218545878: sio_revents: revents = 0x0, took 1467ns
2218560196: sio_revents: revents = 0x0, took 1257ns
2218573256: sio_revents: revents = 0x0, took 1257ns
2218585828: sio_revents: revents = 0x0, took 1257ns
02220860349: clk  +111   +0, wr  +119   +0 rd:  +110   +0
2220858812: sio_revents: revents = 0x1, took 5308ns
2220892336: sio_revents: revents = 0x0, took 1187ns
02240928124: clk  +112   +0, wr  +120   +0 rd:  +111   +0
2240926727: sio_revents: revents = 0x1, took 4051ns
2240958016: sio_revents: revents = 0x0, took 1257ns
2248589503: sio_revents: revents = 0x0, took 1327ns
2248604100: sio_revents: revents = 0x0, took 1257ns
2248617091: sio_revents: revents = 0x0, took 1257ns
2248629592: sio_revents: revents = 0x0, took 1257ns
2248642303: sio_revents: revents = 0x0, took 1257ns
2248654805: sio_revents: revents = 0x0, took 1327ns
2248667446: sio_revents: revents = 0x0, took 1257ns
2248679878: sio_revents: revents = 0x0, took 1257ns
02260861176: clk  +113   +0, wr  +121   +0 rd:  +112   +0
2260859639: sio_revents: revents = 0x1, took 5378ns
2260893163: sio_revents: revents = 0x0, took 1257ns
2278507973: sio_revents: revents = 0x0, took 1327ns
2278521522: sio_revents: revents = 0x0, took 1257ns
2278534512: sio_revents: revents = 0x0, took 1258ns
2278547433: sio_revents: revents = 0x0, took 1257ns
02280945503: clk  +114   +0, wr  +122   +0 rd:  +113   +0
2280943967: sio_revents: revents = 0x1, took 5098ns
2280977351: sio_revents: revents = 0x0, took 1257ns
02300859768: clk  +115   +0, wr  +123   +0 rd:  +114   +0
2300858441: sio_revents: revents = 0x1, took 3212ns
2300888542: sio_revents: revents = 0x0, took 1187ns
2308586937: sio_revents: revents = 0x0, took 1397ns
2308601464: sio_revents: revents = 0x0, took 1258ns
2308614664: sio_revents: revents = 0x0, took 1257ns
2308627236: sio_revents: revents = 0x0, took 1257ns
2308640087: sio_revents: revents = 0x0, took 1187ns
2308652449: sio_revents: revents = 0x0, took 1257ns
2308666417: sio_revents: revents = 0x0, took 1257ns
2308678988: sio_revents: revents = 0x0, took 1257ns
02320955549: clk  +116   +0, wr  +124   +0 rd:  +115   +0
2320954013: sio_revents: revents = 0x1, took 5168ns
2320987187: sio_revents: revents = 0x0, took 1258ns
2338545984: sio_revents: revents = 0x0, took 1467ns
2338560302: sio_revents: revents = 0x0, took 1257ns
2338573362: sio_revents: revents = 0x0, took 1257ns
2338585934: sio_revents: revents = 0x0, took 1257ns
02340860944: clk  +117   +0, wr  +125   +0 rd:  +116   +0
2340859477: sio_revents: revents = 0x1, took 5308ns
2340893071: sio_revents: revents = 0x0, took 1257ns
02360969018: clk  +118   +0, wr  +126   +0 rd:  +117   +0
2360967760: sio_revents: revents = 0x1, took 3353ns
2360998560: sio_revents: revents = 0x0, took 1258ns
2368556016: sio_revents: revents = 0x0, took 1327ns
2368615241: sio_revents: revents = 0x0, took 1467ns
2368630606: sio_revents: revents = 0x0, took 1257ns
2368643387: sio_revents: revents = 0x0, took 1257ns
2368656029: sio_revents: revents = 0x0, took 1327ns
2368668740: sio_revents: revents = 0x0, took 1257ns
2368681311: sio_revents: revents = 0x0, took 1257ns
2368693882: sio_revents: revents = 0x0, took 1258ns
02380860025: clk  +119   +0, wr  +127   +0 rd:  +118   +0
2380858488: sio_revents: revents = 0x1, took 5308ns
2380891733: sio_revents: revents = 0x0, took 1257ns
2398556898: sio_revents: revents = 0x0, took 1467ns
2398571495: sio_revents: revents = 0x0, took 1187ns
2398584555: sio_revents: revents = 0x0, took 1257ns
2398597126: sio_revents: revents = 0x0, took 1258ns
02400981578: clk  +120   +0, wr  +128   +0 rd:  +119   +0
2400980041: sio_revents: revents = 0x1, took 5308ns
2401013705: sio_revents: revents = 0x0, took 1187ns
02420862598: clk  +121   +0, wr  +129   +0 rd:  +120   +0
2420861340: sio_revents: revents = 0x1, took 3353ns
2420891791: sio_revents: revents = 0x0, took 1257ns
2428585298: sio_revents: revents = 0x0, took 1396ns
2428599825: sio_revents: revents = 0x0, took 1257ns
2428614491: sio_revents: revents = 0x0, took 1257ns
2428626993: sio_revents: revents = 0x0, took 1257ns
2428639774: sio_revents: revents = 0x0, took 1187ns
2428652205: sio_revents: revents = 0x0, took 1258ns
2428665056: sio_revents: revents = 0x0, took 1257ns
2428677558: sio_revents: revents = 0x0, took 1257ns
02440993021: clk  +122   +0, wr  +130   +0 rd:  +121   +0
2440991554: sio_revents: revents = 0x1, took 5238ns
2441024728: sio_revents: revents = 0x0, took 1188ns
2458507887: sio_revents: revents = 0x0, took 1397ns
2458521507: sio_revents: revents = 0x0, took 1257ns
2458534427: sio_revents: revents = 0x0, took 1188ns
2458546859: sio_revents: revents = 0x0, took 1257ns
02460876624: clk  +123   +0, wr  +131   +0 rd:  +122   +0
2460875088: sio_revents: revents = 0x1, took 5168ns
2460908472: sio_revents: revents = 0x0, took 1257ns
02480859822: clk  +124   +0, wr  +132   +0 rd:  +123   +0
2480858565: sio_revents: revents = 0x1, took 3282ns
2480888597: sio_revents: revents = 0x0, took 1187ns
2488589855: sio_revents: revents = 0x0, took 1397ns
2488604243: sio_revents: revents = 0x0, took 1257ns
2488617233: sio_revents: revents = 0x0, took 1257ns
2488629735: sio_revents: revents = 0x0, took 1257ns
2488642446: sio_revents: revents = 0x0, took 1187ns
2488654878: sio_revents: revents = 0x0, took 1257ns
2488667309: sio_revents: revents = 0x0, took 1257ns
2488679811: sio_revents: revents = 0x0, took 1187ns
02500883178: clk  +125   +0, wr  +133   +0 rd:  +124   +0
2500881712: sio_revents: revents = 0x1, took 5238ns
2500914816: sio_revents: revents = 0x0, took 1258ns
2518547925: sio_revents: revents = 0x0, took 1397ns
2518562382: sio_revents: revents = 0x0, took 1257ns
2518575442: sio_revents: revents = 0x0, took 1327ns
2518587944: sio_revents: revents = 0x0, took 1257ns
02520861557: clk  +126   +0, wr  +134   +0 rd:  +125   +0
2520860020: sio_revents: revents = 0x1, took 5099ns
2520893335: sio_revents: revents = 0x0, took 1257ns
02540886450: clk  +127   +0, wr  +135   +0 rd:  +126   +0
2540885193: sio_revents: revents = 0x1, took 3212ns
2540916412: sio_revents: revents = 0x0, took 1257ns
2548551181: sio_revents: revents = 0x0, took 1327ns
2548565429: sio_revents: revents = 0x0, took 1257ns
2548578350: sio_revents: revents = 0x0, took 1257ns
2548590921: sio_revents: revents = 0x0, took 1257ns
2548603492: sio_revents: revents = 0x0, took 1258ns
2548615994: sio_revents: revents = 0x0, took 1257ns
2548628635: sio_revents: revents = 0x0, took 1258ns
2548641067: sio_revents: revents = 0x0, took 1257ns
02560861127: clk  +128   +0, wr  +136   +0 rd:  +127   +0
2560859590: sio_revents: revents = 0x1, took 5169ns
2560892625: sio_revents: revents = 0x0, took 1257ns
2578547524: sio_revents: revents = 0x0, took 1397ns
2578561841: sio_revents: revents = 0x0, took 1188ns
2578574832: sio_revents: revents = 0x0, took 1187ns
2578587263: sio_revents: revents = 0x0, took 1258ns
02580892235: clk  +129   +0, wr  +137   +0 rd:  +128   +0
2580890699: sio_revents: revents = 0x1, took 5098ns
2580924083: sio_revents: revents = 0x0, took 1187ns
02600860557: clk  +130   +0, wr  +138   +0 rd:  +129   +0
2600859230: sio_revents: revents = 0x1, took 3282ns
2600889192: sio_revents: revents = 0x0, took 1327ns
2608554971: sio_revents: revents = 0x0, took 1397ns
2608569289: sio_revents: revents = 0x0, took 1257ns
2608582209: sio_revents: revents = 0x0, took 1257ns
2608594711: sio_revents: revents = 0x0, took 1257ns
2608607422: sio_revents: revents = 0x0, took 1257ns
2608619923: sio_revents: revents = 0x0, took 1258ns
2608632565: sio_revents: revents = 0x0, took 1257ns
2608644996: sio_revents: revents = 0x0, took 1257ns
02620889989: clk  +131   +0, wr  +139   +0 rd:  +130   +0
2620888523: sio_revents: revents = 0x1, took 5098ns
2620921558: sio_revents: revents = 0x0, took 1257ns
2638549986: sio_revents: revents = 0x0, took 1537ns
2638565561: sio_revents: revents = 0x0, took 1257ns
2638578691: sio_revents: revents = 0x0, took 1257ns
2638591193: sio_revents: revents = 0x0, took 1187ns
02640861663: clk  +132   +0, wr  +140   +0 rd:  +131   +0
2640860127: sio_revents: revents = 0x1, took 5377ns
2640905873: sio_revents: revents = 0x0, took 1257ns
02660883413: clk  +133   +0, wr  +141   +0 rd:  +132   +0
2660882156: sio_revents: revents = 0x1, took 3422ns
2660912537: sio_revents: revents = 0x0, took 1187ns
2668588583: sio_revents: revents = 0x0, took 1397ns
2668603110: sio_revents: revents = 0x0, took 1257ns
2668616240: sio_revents: revents = 0x0, took 1257ns
2668628742: sio_revents: revents = 0x0, took 1327ns
2668641523: sio_revents: revents = 0x0, took 1257ns
2668654024: sio_revents: revents = 0x0, took 1257ns
2668667084: sio_revents: revents = 0x0, took 1257ns
2668679586: sio_revents: revents = 0x0, took 1257ns
02680860255: clk  +134   +0, wr  +142   +0 rd:  +133   +0
2680858719: sio_revents: revents = 0x1, took 5307ns
2680891963: sio_revents: revents = 0x0, took 1257ns
2698508938: sio_revents: revents = 0x0, took 1327ns
2698522417: sio_revents: revents = 0x0, took 1258ns
2698535408: sio_revents: revents = 0x0, took 1257ns
2698547979: sio_revents: revents = 0x0, took 1257ns
02700879910: clk  +135   +0, wr  +143   +0 rd:  +134   +0
2700878303: sio_revents: revents = 0x1, took 5169ns
2700911757: sio_revents: revents = 0x0, took 1258ns
02720860104: clk  +136   +0, wr  +144   +0 rd:  +135   +0
2720858707: sio_revents: revents = 0x1, took 3842ns
2720889717: sio_revents: revents = 0x0, took 1257ns
2728588601: sio_revents: revents = 0x0, took 1397ns
2728603128: sio_revents: revents = 0x0, took 1257ns
2728616258: sio_revents: revents = 0x0, took 1257ns
2728628829: sio_revents: revents = 0x0, took 1258ns
2728641541: sio_revents: revents = 0x0, took 1257ns
2728654112: sio_revents: revents = 0x0, took 1257ns
2728666823: sio_revents: revents = 0x0, took 1257ns
2728679255: sio_revents: revents = 0x0, took 1257ns
02740876756: clk  +137   +0, wr  +145   +0 rd:  +136   +0
2740875150: sio_revents: revents = 0x1, took 5377ns
2740908394: sio_revents: revents = 0x0, took 1187ns
2758548207: sio_revents: revents = 0x0, took 1536ns
2758563293: sio_revents: revents = 0x0, took 1257ns
2758576213: sio_revents: revents = 0x0, took 1257ns
2758591090: sio_revents: revents = 0x0, took 1257ns
02760860931: clk  +138   +0, wr  +146   +0 rd:  +137   +0
2760859395: sio_revents: revents = 0x1, took 5308ns
2760892988: sio_revents: revents = 0x0, took 1327ns
02780876815: clk  +139   +0, wr  +147   +0 rd:  +138   +0
2780875418: sio_revents: revents = 0x1, took 3562ns
2780905869: sio_revents: revents = 0x0, took 1257ns
2788555235: sio_revents: revents = 0x0, took 1327ns
2788569483: sio_revents: revents = 0x0, took 1257ns
2788582613: sio_revents: revents = 0x0, took 1257ns
2788595184: sio_revents: revents = 0x0, took 1257ns
2788607965: sio_revents: revents = 0x0, took 1257ns
2788620467: sio_revents: revents = 0x0, took 1257ns
2788633178: sio_revents: revents = 0x0, took 1257ns
2788645610: sio_revents: revents = 0x0, took 1257ns
02800860361: clk  +140   +0, wr  +148   +0 rd:  +139   +0
2800858825: sio_revents: revents = 0x1, took 5238ns
2800891999: sio_revents: revents = 0x0, took 1258ns
2818547876: sio_revents: revents = 0x0, took 1397ns
2818562124: sio_revents: revents = 0x0, took 1257ns
2818575323: sio_revents: revents = 0x0, took 1258ns
2818587895: sio_revents: revents = 0x0, took 1257ns
02820878759: clk  +141   +0, wr  +149   +0 rd:  +140   +0
2820877152: sio_revents: revents = 0x1, took 5308ns
2820910606: sio_revents: revents = 0x0, took 1258ns
02840860071: clk  +142   +0, wr  +150   +0 rd:  +141   +0
2840858813: sio_revents: revents = 0x1, took 3283ns
2840888845: sio_revents: revents = 0x0, took 1188ns
2848586682: sio_revents: revents = 0x0, took 1466ns
2848601209: sio_revents: revents = 0x0, took 1257ns
2848614339: sio_revents: revents = 0x0, took 1257ns
2848626910: sio_revents: revents = 0x0, took 1257ns
2848639761: sio_revents: revents = 0x0, took 1187ns
2848652333: sio_revents: revents = 0x0, took 1257ns
2848664974: sio_revents: revents = 0x0, took 1187ns
2848677406: sio_revents: revents = 0x0, took 1257ns
02860879446: clk  +143   +0, wr  +151   +0 rd:  +142   +0
2860877840: sio_revents: revents = 0x1, took 5308ns
2860912551: sio_revents: revents = 0x0, took 1257ns
2878508853: sio_revents: revents = 0x0, took 1397ns
2878522402: sio_revents: revents = 0x0, took 1257ns
2878535253: sio_revents: revents = 0x0, took 1257ns
2878547824: sio_revents: revents = 0x0, took 1257ns
02880861875: clk  +144   +0, wr  +152   +0 rd:  +143   +0
2880860269: sio_revents: revents = 0x1, took 5029ns
2880893374: sio_revents: revents = 0x0, took 1187ns
02900886629: clk  +145   +0, wr  +153   +0 rd:  +144   +0
2900884952: sio_revents: revents = 0x1, took 5169ns
2900917708: sio_revents: revents = 0x0, took 1257ns
2908598224: sio_revents: revents = 0x0, took 1397ns
2908612821: sio_revents: revents = 0x0, took 1257ns
2908626021: sio_revents: revents = 0x0, took 1257ns
2908638592: sio_revents: revents = 0x0, took 1257ns
2908651303: sio_revents: revents = 0x0, took 1257ns
2908663805: sio_revents: revents = 0x0, took 1257ns
2908676446: sio_revents: revents = 0x0, took 1257ns
2908688878: sio_revents: revents = 0x0, took 1257ns
02920860467: clk  +146   +0, wr  +154   +0 rd:  +145   +0
2920858931: sio_revents: revents = 0x1, took 5378ns
2920892315: sio_revents: revents = 0x0, took 1187ns
2938546934: sio_revents: revents = 0x0, took 1327ns
2938561252: sio_revents: revents = 0x0, took 1257ns
2938574172: sio_revents: revents = 0x0, took 1328ns
2938586744: sio_revents: revents = 0x0, took 1257ns
02940896605: clk  +147   +0, wr  +155   +0 rd:  +146   +0
2940895068: sio_revents: revents = 0x1, took 5168ns
2940928382: sio_revents: revents = 0x0, took 1258ns
02960860037: clk  +148   +0, wr  +156   +0 rd:  +147   +0
2960858710: sio_revents: revents = 0x1, took 3283ns
2960889371: sio_revents: revents = 0x0, took 1187ns
2968554382: sio_revents: revents = 0x0, took 1466ns
2968568909: sio_revents: revents = 0x0, took 1187ns
2968581899: sio_revents: revents = 0x0, took 1257ns
2968594610: sio_revents: revents = 0x0, took 1188ns
2968607251: sio_revents: revents = 0x0, took 1257ns
2968619823: sio_revents: revents = 0x0, took 1187ns
2968632464: sio_revents: revents = 0x0, took 1187ns
2968646432: sio_revents: revents = 0x0, took 1188ns
02980900086: clk  +149   +0, wr  +157   +0 rd:  +148   +0
2980898549: sio_revents: revents = 0x1, took 5168ns
2980931793: sio_revents: revents = 0x0, took 1258ns
2998550584: sio_revents: revents = 0x0, took 1467ns
2998564902: sio_revents: revents = 0x0, took 1257ns
2998577892: sio_revents: revents = 0x0, took 1257ns
2998590394: sio_revents: revents = 0x0, took 1187ns
03000861842: clk  +150   +0, wr  +158   +0 rd:  +149   +0
3000860305: sio_revents: revents = 0x1, took 5238ns
3000893550: sio_revents: revents = 0x0, took 1257ns
03020903078: clk  +151   +0, wr  +159   +0 rd:  +150   +0
3020901821: sio_revents: revents = 0x1, took 3212ns
3020931782: sio_revents: revents = 0x0, took 1258ns
3028554539: sio_revents: revents = 0x0, took 1467ns
3028568996: sio_revents: revents = 0x0, took 1258ns
3028581987: sio_revents: revents = 0x0, took 1257ns
3028594558: sio_revents: revents = 0x0, took 1258ns
3028607200: sio_revents: revents = 0x0, took 1257ns
3028619701: sio_revents: revents = 0x0, took 1257ns
3028632343: sio_revents: revents = 0x0, took 1257ns
3028644844: sio_revents: revents = 0x0, took 1257ns
03040860644: clk  +152   +0, wr  +160   +0 rd:  +151   +0
3040859107: sio_revents: revents = 0x1, took 5168ns
3040892421: sio_revents: revents = 0x0, took 1257ns
3058547110: sio_revents: revents = 0x0, took 1397ns
3058561358: sio_revents: revents = 0x0, took 1257ns
3058574209: sio_revents: revents = 0x0, took 1257ns
3058586710: sio_revents: revents = 0x0, took 1258ns
03060909771: clk  +153   +0, wr  +161   +0 rd:  +152   +0
3060908235: sio_revents: revents = 0x1, took 5238ns
3060941689: sio_revents: revents = 0x0, took 1187ns
03080860213: clk  +154   +0, wr  +162   +0 rd:  +153   +0
3080858956: sio_revents: revents = 0x1, took 3283ns
3080889128: sio_revents: revents = 0x0, took 1187ns
3088588361: sio_revents: revents = 0x0, took 1397ns
3088602818: sio_revents: revents = 0x0, took 1257ns
3088615948: sio_revents: revents = 0x0, took 1257ns
3088628519: sio_revents: revents = 0x0, took 1258ns
3088642837: sio_revents: revents = 0x0, took 1257ns
3088655408: sio_revents: revents = 0x0, took 1257ns
3088668050: sio_revents: revents = 0x0, took 1257ns
3088680481: sio_revents: revents = 0x0, took 1257ns
03100911995: clk  +155   +0, wr  +163   +0 rd:  +154   +0
3100910458: sio_revents: revents = 0x1, took 5169ns
3100943703: sio_revents: revents = 0x0, took 1257ns
3118548805: sio_revents: revents = 0x0, took 1397ns
3118563122: sio_revents: revents = 0x0, took 1257ns
3118576113: sio_revents: revents = 0x0, took 1257ns
3118588684: sio_revents: revents = 0x0, took 1257ns
03120861389: clk  +156   +0, wr  +164   +0 rd:  +155   +0
3120859853: sio_revents: revents = 0x1, took 5238ns
3120893446: sio_revents: revents = 0x0, took 1258ns
03140910796: clk  +157   +0, wr  +165   +0 rd:  +156   +0
3140909469: sio_revents: revents = 0x1, took 3353ns
3140939571: sio_revents: revents = 0x0, took 1257ns
3148554855: sio_revents: revents = 0x0, took 1397ns
3148614430: sio_revents: revents = 0x0, took 1536ns
3148629795: sio_revents: revents = 0x0, took 1257ns
3148642506: sio_revents: revents = 0x0, took 1257ns
3148655217: sio_revents: revents = 0x0, took 1187ns
3148667719: sio_revents: revents = 0x0, took 1257ns
3148680360: sio_revents: revents = 0x0, took 1257ns
3148692862: sio_revents: revents = 0x0, took 1257ns
03160860889: clk  +158   +0, wr  +166   +0 rd:  +157   +0
3160859353: sio_revents: revents = 0x1, took 5238ns
3160892946: sio_revents: revents = 0x0, took 1188ns
3178547705: sio_revents: revents = 0x0, took 1467ns
3178562372: sio_revents: revents = 0x0, took 1257ns
3178575293: sio_revents: revents = 0x0, took 1257ns
3178587794: sio_revents: revents = 0x0, took 1257ns
03180911693: clk  +159   +0, wr  +167   +0 rd:  +158   +0
3180910157: sio_revents: revents = 0x1, took 5168ns
3180943541: sio_revents: revents = 0x0, took 1257ns
03200860669: clk  +160   +0, wr  +168   +0 rd:  +159   +0
3200859272: sio_revents: revents = 0x1, took 4819ns
3200891888: sio_revents: revents = 0x0, took 1257ns
3208557038: sio_revents: revents = 0x0, took 1397ns
3208571635: sio_revents: revents = 0x0, took 1327ns
3208584975: sio_revents: revents = 0x0, took 1257ns
3208597616: sio_revents: revents = 0x0, took 1257ns
3208610397: sio_revents: revents = 0x0, took 1257ns
3208622968: sio_revents: revents = 0x0, took 1258ns
3208635680: sio_revents: revents = 0x0, took 1257ns
3208648181: sio_revents: revents = 0x0, took 1257ns
3214659700: sio_revents: revents = 0x0, took 1536ns
mplayer0 vol=127,pst=run,mmc=off,rmsg,widl: STOP message
mplayer0 vol=127,pst=run,mmc=off: stopping
03220909307: clk  +161   +0, wr  +169   +0 rd:  +160   +0
3220907980: sio_revents: revents = 0x1, took 3772ns
03240860588: clk  +162   +0, wr  +170   +0 rd:  +161   +0
3240859330: sio_revents: revents = 0x1, took 3283ns
03260911671: clk  +163   +0, wr  +171   +0 rd:  +162   +0
3260910204: sio_revents: revents = 0x1, took 4121ns
03280861414: clk  +164   +0, wr  +172   +0 rd:  +163   +0
3280860087: sio_revents: revents = 0x1, took 3423ns
03300911730: clk  +165   +0, wr  +173   +0 rd:  +164   +0
3300910333: sio_revents: revents = 0x1, took 3282ns
03320860775: clk  +166   +0, wr  +174   +0 rd:  +165   +0
3320859308: sio_revents: revents = 0x1, took 5029ns
03340919820: clk  +167   +0, wr  +175   +0 rd:  +166   +0
3340918563: sio_revents: revents = 0x1, took 3213ns
03360860554: clk  +168   +0, wr  +176   +0 rd:  +167   +0
3360859297: sio_revents: revents = 0x1, took 3143ns
03380927422: clk  +169   +0, wr  +177   +0 rd:  +168   +0
3380926094: sio_revents: revents = 0x1, took 3213ns
03400860473: clk  +170   +0, wr  +178   +0 rd:  +169   +0
3400859146: sio_revents: revents = 0x1, took 3352ns
03420928248: clk  +171   +0, wr  +179   +0 rd:  +170   +0
3420926712: sio_revents: revents = 0x1, took 4679ns
03440860532: clk  +172   +0, wr  +180   +0 rd:  +171   +0
3440859275: sio_revents: revents = 0x1, took 3212ns
03460926002: clk  +173   +0, wr  +181   +0 rd:  +172   +0
3460924745: sio_revents: revents = 0x1, took 3213ns
03480860590: clk  +174   +0, wr  +182   +0 rd:  +173   +0
3480859263: sio_revents: revents = 0x1, took 4610ns
mplayer0 vol=127,pst=ini,mmc=off,rmsg,widl: stopped
3480878400: sio_revents: revents = 0x0, took 1187ns
mplayer0 vol=127,pst=ini,mmc=off,rmsg,widl: building STOP message
3480893276: sio_revents: revents = 0x0, took 1257ns
mplayer0 vol=127,pst=ini,mmc=off,rmsg,widl: GETPAR message
3480902984: sio_revents: revents = 0x0, took 1257ns
3481502851: sio_revents: revents = 0x0, took 1397ns
mplayer0 vol=127,pst=ini,mmc=off,rmsg,widl: START message
mplayer0 vol=127,pst=ini,mmc=off: playing s32le -> s16le
mplayer0 vol=127,pst=ini,mmc=off: allocated 11466/19404 fr buffers
mplayer0 vol=127,pst=sta,mmc=off: 44100Hz, s32le, play 0:1, 13 blocks of 882 frames
3481515492: sio_revents: revents = 0x0, took 1257ns
3481534419: sio_revents: revents = 0x0, took 1257ns
mplayer0 vol=127,pst=run,mmc=off: attached at -7938, delta = 0
cmap: nch = 2, ostart = 0, onext = 0, istart = 0, inext = 0
dec: s32le, 2 channels
resamp: 882/960
mplayer0 vol=127,pst=run,mmc=off: set weight: 23170/23170
03500924385: clk  +175   +0, wr  +183   +0 rd:  +174   +0
3500922988: sio_revents: revents = 0x1, took 3911ns
3500954626: sio_revents: revents = 0x0, took 1257ns
3500972435: sio_revents: revents = 0x0, took 1258ns
03520861417: clk  +176   +0, wr  +184   +0 rd:  +175   +0
3520860090: sio_revents: revents = 0x1, took 3492ns
3520890471: sio_revents: revents = 0x0, took 1188ns
3520907582: sio_revents: revents = 0x0, took 1257ns
03540919205: clk  +177   +0, wr  +185   +0 rd:  +176   +0
3540917809: sio_revents: revents = 0x1, took 3771ns
3540948958: sio_revents: revents = 0x0, took 1257ns
3540966628: sio_revents: revents = 0x0, took 1257ns
03560861406: clk  +178   +0, wr  +186   +0 rd:  +177   +0
3560860149: sio_revents: revents = 0x1, took 3282ns
3560890250: sio_revents: revents = 0x0, took 1188ns
3560907292: sio_revents: revents = 0x0, took 1257ns
03580911582: clk  +179   +0, wr  +187   +0 rd:  +178   +0
3580910254: sio_revents: revents = 0x1, took 3353ns
3580940216: sio_revents: revents = 0x0, took 1257ns
3580958445: sio_revents: revents = 0x0, took 1257ns
03600860906: clk  +180   +0, wr  +188   +0 rd:  +179   +0
3600859649: sio_revents: revents = 0x1, took 3282ns
3600889960: sio_revents: revents = 0x0, took 1187ns
3600907071: sio_revents: revents = 0x0, took 1257ns
3601219820: sio_revents: revents = 0x0, took 1397ns
3601234278: sio_revents: revents = 0x0, took 1257ns
03620915132: clk  +181   +0, wr  +189   +0 rd:  +180   +0
3620913526: sio_revents: revents = 0x1, took 4539ns
3620946002: sio_revents: revents = 0x0, took 1327ns
3620964789: sio_revents: revents = 0x0, took 1257ns
03640860895: clk  +182   +0, wr  +190   +0 rd:  +181   +0
3640859638: sio_revents: revents = 0x1, took 3422ns
3640890019: sio_revents: revents = 0x0, took 1257ns
3640907339: sio_revents: revents = 0x0, took 1257ns
03660914283: clk  +183   +0, wr  +191   +0 rd:  +182   +0
3660913026: sio_revents: revents = 0x1, took 3352ns
3660943058: sio_revents: revents = 0x0, took 1257ns
3660964429: sio_revents: revents = 0x0, took 1257ns
03680861512: clk  +184   +0, wr  +192   +0 rd:  +183   +0
3680859906: sio_revents: revents = 0x1, took 6006ns
3680894128: sio_revents: revents = 0x0, took 1257ns
3688550409: sio_revents: revents = 0x0, took 1397ns
3688565285: sio_revents: revents = 0x0, took 1257ns
3688578485: sio_revents: revents = 0x0, took 1257ns
3688591266: sio_revents: revents = 0x0, took 1187ns
03700912107: clk  +185   +0, wr  +193   +0 rd:  +184   +0
3700910361: sio_revents: revents = 0x1, took 5447ns
3700943675: sio_revents: revents = 0x0, took 1187ns
3718511132: sio_revents: revents = 0x0, took 1327ns
3718524891: sio_revents: revents = 0x0, took 1257ns
3718537882: sio_revents: revents = 0x0, took 1257ns
3718550383: sio_revents: revents = 0x0, took 1257ns
03720862758: clk  +186   +0, wr  +194   +0 rd:  +185   +0
3720861152: sio_revents: revents = 0x1, took 5168ns
3720894466: sio_revents: revents = 0x0, took 1187ns
03740911467: clk  +187   +0, wr  +195   +0 rd:  +186   +0
3740910000: sio_revents: revents = 0x1, took 3911ns
3740941010: sio_revents: revents = 0x0, took 1187ns
3748592961: sio_revents: revents = 0x0, took 1466ns
3748607557: sio_revents: revents = 0x0, took 1257ns
3748620757: sio_revents: revents = 0x0, took 1258ns
3748633399: sio_revents: revents = 0x0, took 1257ns
3748646180: sio_revents: revents = 0x0, took 1257ns
3748658821: sio_revents: revents = 0x0, took 1187ns
3748671532: sio_revents: revents = 0x0, took 1187ns
3748684034: sio_revents: revents = 0x0, took 1187ns
03760861350: clk  +188   +0, wr  +196   +0 rd:  +187   +0
3760859674: sio_revents: revents = 0x1, took 5448ns
3760893058: sio_revents: revents = 0x0, took 1257ns
3778551659: sio_revents: revents = 0x0, took 1536ns
3778566744: sio_revents: revents = 0x0, took 1257ns
3778579804: sio_revents: revents = 0x0, took 1258ns
3778592376: sio_revents: revents = 0x0, took 1257ns
03780913900: clk  +189   +0, wr  +197   +0 rd:  +188   +0
3780912294: sio_revents: revents = 0x1, took 5378ns
3780946516: sio_revents: revents = 0x0, took 1257ns
03800860850: clk  +190   +0, wr  +198   +0 rd:  +189   +0
3800859523: sio_revents: revents = 0x1, took 3422ns
3800889904: sio_revents: revents = 0x0, took 1187ns
3808556731: sio_revents: revents = 0x0, took 1467ns
3808571258: sio_revents: revents = 0x0, took 1257ns
3808584249: sio_revents: revents = 0x0, took 1257ns
3808596820: sio_revents: revents = 0x0, took 1187ns
3808609531: sio_revents: revents = 0x0, took 1257ns
3808622033: sio_revents: revents = 0x0, took 1257ns
3808634604: sio_revents: revents = 0x0, took 1257ns
3808647036: sio_revents: revents = 0x0, took 1257ns
03820912702: clk  +191   +0, wr  +199   +0 rd:  +190   +0
3820911165: sio_revents: revents = 0x1, took 5238ns
3820944410: sio_revents: revents = 0x0, took 1187ns
3838552375: sio_revents: revents = 0x0, took 1397ns
3838566762: sio_revents: revents = 0x0, took 1258ns
3838579753: sio_revents: revents = 0x0, took 1257ns
3838592324: sio_revents: revents = 0x0, took 1257ns
03840862655: clk  +192   +0, wr  +200   +0 rd:  +191   +0
3840861048: sio_revents: revents = 0x1, took 5309ns
3840894502: sio_revents: revents = 0x0, took 1258ns
03860916113: clk  +193   +0, wr  +201   +0 rd:  +192   +0
3860914786: sio_revents: revents = 0x1, took 3352ns
3860944957: sio_revents: revents = 0x0, took 1257ns
3868556889: sio_revents: revents = 0x0, took 1327ns
3868571206: sio_revents: revents = 0x0, took 1257ns
3868584267: sio_revents: revents = 0x0, took 1257ns
3868596768: sio_revents: revents = 0x0, took 1257ns
3868609479: sio_revents: revents = 0x0, took 1258ns
3868621981: sio_revents: revents = 0x0, took 1257ns
3868634692: sio_revents: revents = 0x0, took 1257ns
3868647124: sio_revents: revents = 0x0, took 1187ns
03880861317: clk  +194   +0, wr  +202   +0 rd:  +193   +0
3880859710: sio_revents: revents = 0x1, took 5308ns
3880892815: sio_revents: revents = 0x0, took 1257ns
3898552393: sio_revents: revents = 0x0, took 1397ns
3898566850: sio_revents: revents = 0x0, took 1257ns
3898579771: sio_revents: revents = 0x0, took 1257ns
3898592343: sio_revents: revents = 0x0, took 1187ns
03900910165: clk  +195   +0, wr  +203   +0 rd:  +194   +0
3900908559: sio_revents: revents = 0x1, took 5168ns
3900941943: sio_revents: revents = 0x0, took 1257ns
03920860956: clk  +196   +0, wr  +204   +0 rd:  +195   +0
3920859629: sio_revents: revents = 0x1, took 3492ns
3920890010: sio_revents: revents = 0x0, took 1188ns
3928796323: sio_revents: revents = 0x0, took 1536ns
3928963593: sio_revents: revents = 0x0, took 1536ns
3929079809: sio_revents: revents = 0x0, took 1397ns
3929192044: sio_revents: revents = 0x0, took 1327ns
3929209853: sio_revents: revents = 0x0, took 1257ns
3929222704: sio_revents: revents = 0x0, took 1257ns
3929235555: sio_revents: revents = 0x0, took 1187ns
3929248126: sio_revents: revents = 0x0, took 1257ns
03940904986: clk  +197   +0, wr  +205   +0 rd:  +196   +0
3940903379: sio_revents: revents = 0x1, took 5588ns
3940937252: sio_revents: revents = 0x0, took 1257ns
3958516583: sio_revents: revents = 0x0, took 1606ns
3958532926: sio_revents: revents = 0x0, took 1257ns
3958546265: sio_revents: revents = 0x0, took 1257ns
3958560373: sio_revents: revents = 0x0, took 1257ns
03960862971: clk  +198   +0, wr  +206   +0 rd:  +197   +0
3960861294: sio_revents: revents = 0x1, took 5727ns
3960895726: sio_revents: revents = 0x0, took 1257ns
03980903997: clk  +199   +0, wr  +207   +0 rd:  +198   +0
3980902670: sio_revents: revents = 0x1, took 3422ns
3980932841: sio_revents: revents = 0x0, took 1187ns
3988592824: sio_revents: revents = 0x0, took 1396ns
3988607490: sio_revents: revents = 0x0, took 1257ns
3988620620: sio_revents: revents = 0x0, took 1258ns
3988633192: sio_revents: revents = 0x0, took 1257ns
3988645903: sio_revents: revents = 0x0, took 1257ns
3988658405: sio_revents: revents = 0x0, took 1257ns
3988671325: sio_revents: revents = 0x0, took 1257ns
3988683757: sio_revents: revents = 0x0, took 1257ns
04000861493: clk  +200   +0, wr  +208   +0 rd:  +199   +0
4000859956: sio_revents: revents = 0x1, took 5448ns
4000893550: sio_revents: revents = 0x0, took 1257ns
4018550823: sio_revents: revents = 0x0, took 1327ns
4018565210: sio_revents: revents = 0x0, took 1258ns
4018578061: sio_revents: revents = 0x0, took 1257ns
4018590633: sio_revents: revents = 0x0, took 1187ns
04020912855: clk  +201   +0, wr  +209   +0 rd:  +200   +0
4020911249: sio_revents: revents = 0x1, took 5378ns
4020944773: sio_revents: revents = 0x0, took 1257ns
04040861412: clk  +202   +0, wr  +210   +0 rd:  +201   +0
4040860085: sio_revents: revents = 0x1, took 3282ns
4040890116: sio_revents: revents = 0x0, took 1258ns
4048559388: sio_revents: revents = 0x0, took 1327ns
4048573705: sio_revents: revents = 0x0, took 1257ns
4048586766: sio_revents: revents = 0x0, took 1257ns
4048599337: sio_revents: revents = 0x0, took 1257ns
4048612188: sio_revents: revents = 0x0, took 1257ns
4048624619: sio_revents: revents = 0x0, took 1258ns
4048637261: sio_revents: revents = 0x0, took 1257ns
4048649693: sio_revents: revents = 0x0, took 1257ns
04060921644: clk  +203   +0, wr  +211   +0 rd:  +202   +0
4060920108: sio_revents: revents = 0x1, took 5238ns
4060953282: sio_revents: revents = 0x0, took 1188ns
4078550702: sio_revents: revents = 0x0, took 1396ns
4078565089: sio_revents: revents = 0x0, took 1327ns
4078578149: sio_revents: revents = 0x0, took 1257ns
4078590651: sio_revents: revents = 0x0, took 1257ns
04080862448: clk  +204   +0, wr  +212   +0 rd:  +203   +0
4080860842: sio_revents: revents = 0x1, took 5238ns
4080894226: sio_revents: revents = 0x0, took 1257ns
04100932039: clk  +205   +0, wr  +213   +0 rd:  +204   +0
4100930712: sio_revents: revents = 0x1, took 3423ns
4100960954: sio_revents: revents = 0x0, took 1187ns
4108591184: sio_revents: revents = 0x0, took 1397ns
4108605781: sio_revents: revents = 0x0, took 1257ns
4108618701: sio_revents: revents = 0x0, took 1257ns
4108631273: sio_revents: revents = 0x0, took 1257ns
4108644054: sio_revents: revents = 0x0, took 1187ns
4108656555: sio_revents: revents = 0x0, took 1188ns
4108668987: sio_revents: revents = 0x0, took 1257ns
4108681488: sio_revents: revents = 0x0, took 1188ns
04120862646: clk  +206   +0, wr  +214   +0 rd:  +205   +0
4120861040: sio_revents: revents = 0x1, took 5448ns
4120894494: sio_revents: revents = 0x0, took 1257ns
4138511259: sio_revents: revents = 0x0, took 1258ns
4138524739: sio_revents: revents = 0x0, took 1257ns
4138537799: sio_revents: revents = 0x0, took 1188ns
4138550371: sio_revents: revents = 0x0, took 1187ns
04140934682: clk  +207   +0, wr  +215   +0 rd:  +206   +0
4140933146: sio_revents: revents = 0x1, took 5238ns
4140966600: sio_revents: revents = 0x0, took 1187ns
04160861937: clk  +208   +0, wr  +216   +0 rd:  +207   +0
4160860680: sio_revents: revents = 0x1, took 3282ns
4160890781: sio_revents: revents = 0x0, took 1257ns
4168590573: sio_revents: revents = 0x0, took 1327ns
4168604961: sio_revents: revents = 0x0, took 1257ns
4168617951: sio_revents: revents = 0x0, took 1187ns
4168630523: sio_revents: revents = 0x0, took 1257ns
4168643234: sio_revents: revents = 0x0, took 1257ns
4168655735: sio_revents: revents = 0x0, took 1257ns
4168668446: sio_revents: revents = 0x0, took 1258ns
4168680878: sio_revents: revents = 0x0, took 1257ns
04180937814: clk  +209   +0, wr  +217   +0 rd:  +208   +0
4180936277: sio_revents: revents = 0x1, took 5308ns
4180969592: sio_revents: revents = 0x0, took 1187ns
4198553182: sio_revents: revents = 0x0, took 1397ns
4198612687: sio_revents: revents = 0x0, took 1537ns
4198628052: sio_revents: revents = 0x0, took 1257ns
4198640763: sio_revents: revents = 0x0, took 1327ns
04200862834: clk  +210   +0, wr  +218   +0 rd:  +209   +0
4200861227: sio_revents: revents = 0x1, took 5378ns
4200894891: sio_revents: revents = 0x0, took 1187ns
04220936196: clk  +211   +0, wr  +219   +0 rd:  +210   +0
4220934869: sio_revents: revents = 0x1, took 3283ns
4220964901: sio_revents: revents = 0x0, took 1187ns
4228556649: sio_revents: revents = 0x0, took 1466ns
4228571175: sio_revents: revents = 0x0, took 1258ns
4228584306: sio_revents: revents = 0x0, took 1257ns
4228596877: sio_revents: revents = 0x0, took 1257ns
4228609658: sio_revents: revents = 0x0, took 1187ns
4228622090: sio_revents: revents = 0x0, took 1257ns
4228634801: sio_revents: revents = 0x0, took 1257ns
4228647163: sio_revents: revents = 0x0, took 1257ns
04240861775: clk  +212   +0, wr  +220   +0 rd:  +211   +0
4240860238: sio_revents: revents = 0x1, took 5308ns
4240893553: sio_revents: revents = 0x0, took 1257ns
4258551524: sio_revents: revents = 0x0, took 1397ns
4258565772: sio_revents: revents = 0x0, took 1257ns
4258578763: sio_revents: revents = 0x0, took 1257ns
4258591264: sio_revents: revents = 0x0, took 1257ns
04260937931: clk  +213   +0, wr  +221   +0 rd:  +212   +0
4260936325: sio_revents: revents = 0x1, took 5238ns
4260969709: sio_revents: revents = 0x0, took 1257ns
04280861484: clk  +214   +0, wr  +222   +0 rd:  +213   +0
4280860018: sio_revents: revents = 0x1, took 4120ns
4280891446: sio_revents: revents = 0x0, took 1187ns
4288590191: sio_revents: revents = 0x0, took 1396ns
4288604927: sio_revents: revents = 0x0, took 1257ns
4288618057: sio_revents: revents = 0x0, took 1257ns
4288630698: sio_revents: revents = 0x0, took 1258ns
4288643410: sio_revents: revents = 0x0, took 1257ns
4288656889: sio_revents: revents = 0x0, took 1257ns
4288669530: sio_revents: revents = 0x0, took 1188ns
4288681962: sio_revents: revents = 0x0, took 1257ns
04300946441: clk  +215   +0, wr  +223   +0 rd:  +214   +0
4300944834: sio_revents: revents = 0x1, took 5448ns
4300978288: sio_revents: revents = 0x0, took 1188ns
4318511663: sio_revents: revents = 0x0, took 1327ns
4318525212: sio_revents: revents = 0x0, took 1258ns
4318538063: sio_revents: revents = 0x0, took 1188ns
4318550635: sio_revents: revents = 0x0, took 1187ns
04320862521: clk  +216   +0, wr  +224   +0 rd:  +215   +0
4320860914: sio_revents: revents = 0x1, took 5239ns
4320894368: sio_revents: revents = 0x0, took 1258ns
04340951248: clk  +217   +0, wr  +225   +0 rd:  +216   +0
4340949991: sio_revents: revents = 0x1, took 3213ns
4340980023: sio_revents: revents = 0x0, took 1257ns
4348594120: sio_revents: revents = 0x0, took 1397ns
4348608577: sio_revents: revents = 0x0, took 1257ns
4348621567: sio_revents: revents = 0x0, took 1258ns
4348634209: sio_revents: revents = 0x0, took 1187ns
4348646920: sio_revents: revents = 0x0, took 1257ns
4348659421: sio_revents: revents = 0x0, took 1257ns
4348672133: sio_revents: revents = 0x0, took 1257ns
4348684634: sio_revents: revents = 0x0, took 1257ns
04360862091: clk  +218   +0, wr  +226   +0 rd:  +217   +0
4360860484: sio_revents: revents = 0x1, took 5308ns
4360893798: sio_revents: revents = 0x0, took 1258ns
4378550932: sio_revents: revents = 0x0, took 1397ns
4378565389: sio_revents: revents = 0x0, took 1257ns
4378578380: sio_revents: revents = 0x0, took 1257ns
4378590951: sio_revents: revents = 0x0, took 1188ns
04380955567: clk  +219   +0, wr  +227   +0 rd:  +218   +0
4380954031: sio_revents: revents = 0x1, took 5238ns
4380987555: sio_revents: revents = 0x0, took 1257ns
04400861591: clk  +220   +0, wr  +228   +0 rd:  +219   +0
4400860263: sio_revents: revents = 0x1, took 3283ns
4400890295: sio_revents: revents = 0x0, took 1187ns
4408560614: sio_revents: revents = 0x0, took 1397ns
4408576398: sio_revents: revents = 0x0, took 1258ns
4408589459: sio_revents: revents = 0x0, took 1257ns
4408602100: sio_revents: revents = 0x0, took 1257ns
4408614881: sio_revents: revents = 0x0, took 1257ns
4408627382: sio_revents: revents = 0x0, took 1258ns
4408640094: sio_revents: revents = 0x0, took 1257ns
4408652595: sio_revents: revents = 0x0, took 1257ns
04420965963: clk  +221   +0, wr  +229   +0 rd:  +220   +0
4420964426: sio_revents: revents = 0x1, took 5168ns
4420997461: sio_revents: revents = 0x0, took 1257ns
4438550601: sio_revents: revents = 0x0, took 1397ns
4438564849: sio_revents: revents = 0x0, took 1257ns
4438577909: sio_revents: revents = 0x0, took 1257ns
4438590411: sio_revents: revents = 0x0, took 1257ns
04440863256: clk  +222   +0, wr  +230   +0 rd:  +221   +0
4440861719: sio_revents: revents = 0x1, took 5098ns
4440895033: sio_revents: revents = 0x0, took 1257ns
04460972098: clk  +223   +0, wr  +231   +0 rd:  +222   +0
4460970561: sio_revents: revents = 0x1, took 4819ns
4461003177: sio_revents: revents = 0x0, took 1257ns
4468569712: sio_revents: revents = 0x0, took 1467ns
4468584378: sio_revents: revents = 0x0, took 1257ns
4468597439: sio_revents: revents = 0x0, took 1257ns
4468610010: sio_revents: revents = 0x0, took 1257ns
4468622721: sio_revents: revents = 0x0, took 1257ns
4468635223: sio_revents: revents = 0x0, took 1257ns
4468648004: sio_revents: revents = 0x0, took 1187ns
4468660436: sio_revents: revents = 0x0, took 1257ns
04480862686: clk  +224   +0, wr  +232   +0 rd:  +223   +0
4480861149: sio_revents: revents = 0x1, took 5238ns
4480894393: sio_revents: revents = 0x0, took 1258ns
4498552016: sio_revents: revents = 0x0, took 1397ns
4498566194: sio_revents: revents = 0x0, took 1257ns
4498579045: sio_revents: revents = 0x0, took 1257ns
4498591546: sio_revents: revents = 0x0, took 1257ns
04500968734: clk  +225   +0, wr  +233   +0 rd:  +224   +0
4500967197: sio_revents: revents = 0x1, took 5169ns
4501000372: sio_revents: revents = 0x0, took 1257ns
04520861697: clk  +226   +0, wr  +234   +0 rd:  +225   +0
4520860370: sio_revents: revents = 0x1, took 4260ns
4520891728: sio_revents: revents = 0x0, took 1258ns
4528590682: sio_revents: revents = 0x0, took 1327ns
4528605209: sio_revents: revents = 0x0, took 1257ns
4528618200: sio_revents: revents = 0x0, took 1187ns
4528630771: sio_revents: revents = 0x0, took 1188ns
4528643482: sio_revents: revents = 0x0, took 1258ns
4528655984: sio_revents: revents = 0x0, took 1257ns
4528668555: sio_revents: revents = 0x0, took 1257ns
4528680917: sio_revents: revents = 0x0, took 1257ns
04540966628: clk  +227   +0, wr  +235   +0 rd:  +226   +0
4540965091: sio_revents: revents = 0x1, took 5168ns
4540998126: sio_revents: revents = 0x0, took 1257ns
4558512155: sio_revents: revents = 0x0, took 1327ns
4558525704: sio_revents: revents = 0x0, took 1257ns
4558538695: sio_revents: revents = 0x0, took 1326ns
4558551266: sio_revents: revents = 0x0, took 1257ns
04560863362: clk  +228   +0, wr  +236   +0 rd:  +227   +0
4560861825: sio_revents: revents = 0x1, took 5168ns
4560894930: sio_revents: revents = 0x0, took 1257ns
04580964242: clk  +229   +0, wr  +237   +0 rd:  +228   +0
4580962915: sio_revents: revents = 0x1, took 3282ns
4580993016: sio_revents: revents = 0x0, took 1188ns
4588591888: sio_revents: revents = 0x0, took 1396ns
4588606275: sio_revents: revents = 0x0, took 1257ns
4588619335: sio_revents: revents = 0x0, took 1257ns
4588631837: sio_revents: revents = 0x0, took 1187ns
4588644478: sio_revents: revents = 0x0, took 1257ns
4588656980: sio_revents: revents = 0x0, took 1257ns
4588669831: sio_revents: revents = 0x0, took 1187ns
4588682262: sio_revents: revents = 0x0, took 1257ns
04600862093: clk  +230   +0, wr  +238   +0 rd:  +229   +0
4600860557: sio_revents: revents = 0x1, took 5238ns
4600893592: sio_revents: revents = 0x0, took 1187ns
4618551633: sio_revents: revents = 0x0, took 1397ns
4618566160: sio_revents: revents = 0x0, took 1257ns
4618579011: sio_revents: revents = 0x0, took 1257ns
4618591583: sio_revents: revents = 0x0, took 1257ns
04620962345: clk  +231   +0, wr  +239   +0 rd:  +230   +0
4620960808: sio_revents: revents = 0x1, took 24375ns
4621013958: sio_revents: revents = 0x0, took 1257ns
04640861663: clk  +232   +0, wr  +240   +0 rd:  +231   +0
4640860336: sio_revents: revents = 0x1, took 3422ns
4640890647: sio_revents: revents = 0x0, took 1118ns
4648557544: sio_revents: revents = 0x0, took 1467ns
4648572141: sio_revents: revents = 0x0, took 1187ns
4648585201: sio_revents: revents = 0x0, took 1257ns
4648597912: sio_revents: revents = 0x0, took 1187ns
4648610554: sio_revents: revents = 0x0, took 1257ns
4648623125: sio_revents: revents = 0x0, took 1257ns
4648635836: sio_revents: revents = 0x0, took 1257ns
4648648338: sio_revents: revents = 0x0, took 1257ns
04660955908: clk  +233   +0, wr  +241   +0 rd:  +232   +0
4660954302: sio_revents: revents = 0x1, took 5308ns
4660987337: sio_revents: revents = 0x0, took 1257ns
4678552699: sio_revents: revents = 0x0, took 1397ns
4678567017: sio_revents: revents = 0x0, took 1257ns
4678580007: sio_revents: revents = 0x0, took 1257ns
4678592439: sio_revents: revents = 0x0, took 1257ns
04680863398: clk  +234   +0, wr  +242   +0 rd:  +233   +0
4680861861: sio_revents: revents = 0x1, took 5239ns
4680895385: sio_revents: revents = 0x0, took 1258ns
04700946049: clk  +235   +0, wr  +243   +0 rd:  +234   +0
4700944792: sio_revents: revents = 0x1, took 3283ns
4700975034: sio_revents: revents = 0x0, took 1187ns
4708575511: sio_revents: revents = 0x0, took 1397ns
4708590108: sio_revents: revents = 0x0, took 1257ns
4708603168: sio_revents: revents = 0x0, took 1258ns
4708615810: sio_revents: revents = 0x0, took 1257ns
4708628661: sio_revents: revents = 0x0, took 1257ns
4708641232: sio_revents: revents = 0x0, took 1257ns
4708653873: sio_revents: revents = 0x0, took 1257ns
4708666375: sio_revents: revents = 0x0, took 1187ns
04720863666: clk  +236   +0, wr  +244   +0 rd:  +235   +0
4720862060: sio_revents: revents = 0x1, took 5936ns
4720896491: sio_revents: revents = 0x0, took 1258ns
4738535676: sio_revents: revents = 0x0, took 1467ns
4738549784: sio_revents: revents = 0x0, took 1257ns
4738565219: sio_revents: revents = 0x0, took 1257ns
4738577860: sio_revents: revents = 0x0, took 1257ns
04740933258: clk  +237   +0, wr  +245   +0 rd:  +236   +0
4740931651: sio_revents: revents = 0x1, took 5308ns
4740965175: sio_revents: revents = 0x0, took 1257ns
04760862607: clk  +238   +0, wr  +246   +0 rd:  +237   +0
4760861350: sio_revents: revents = 0x1, took 3283ns
4760891592: sio_revents: revents = 0x0, took 1187ns
4768592710: sio_revents: revents = 0x0, took 1397ns
4768607237: sio_revents: revents = 0x0, took 1258ns
4768620298: sio_revents: revents = 0x0, took 1257ns
4768632939: sio_revents: revents = 0x0, took 1257ns
4768645650: sio_revents: revents = 0x0, took 1257ns
4768658222: sio_revents: revents = 0x0, took 1257ns
4768670863: sio_revents: revents = 0x0, took 1257ns
4768683365: sio_revents: revents = 0x0, took 1257ns
04780924446: clk  +239   +0, wr  +247   +0 rd:  +238   +0
4780922910: sio_revents: revents = 0x1, took 5308ns
4780956224: sio_revents: revents = 0x0, took 1257ns
4798553574: sio_revents: revents = 0x0, took 1466ns
4798568729: sio_revents: revents = 0x0, took 1257ns
4798581789: sio_revents: revents = 0x0, took 1257ns
4798594361: sio_revents: revents = 0x0, took 1257ns
04800863644: clk  +240   +0, wr  +248   +0 rd:  +239   +0
4800862107: sio_revents: revents = 0x1, took 5238ns
4800895492: sio_revents: revents = 0x0, took 1187ns
04820920105: clk  +241   +0, wr  +249   +0 rd:  +240   +0
4820918778: sio_revents: revents = 0x1, took 3492ns
4820949229: sio_revents: revents = 0x0, took 1257ns
4828559065: sio_revents: revents = 0x0, took 1257ns
4828573452: sio_revents: revents = 0x0, took 1257ns
4828586373: sio_revents: revents = 0x0, took 1327ns
4828598945: sio_revents: revents = 0x0, took 1257ns
4828611795: sio_revents: revents = 0x0, took 1258ns
4828624297: sio_revents: revents = 0x0, took 1257ns
4828637008: sio_revents: revents = 0x0, took 1257ns
4828649649: sio_revents: revents = 0x0, took 1257ns
04840862515: clk  +242   +0, wr  +250   +0 rd:  +241   +0
4840860909: sio_revents: revents = 0x1, took 6635ns
4840895550: sio_revents: revents = 0x0, took 1257ns
4858551566: sio_revents: revents = 0x0, took 1397ns
4858565884: sio_revents: revents = 0x0, took 1257ns
4858578874: sio_revents: revents = 0x0, took 1257ns
4858591236: sio_revents: revents = 0x0, took 1188ns
04860911992: clk  +243   +0, wr  +251   +0 rd:  +242   +0
4860910386: sio_revents: revents = 0x1, took 5168ns
4860943630: sio_revents: revents = 0x0, took 1187ns
04880862015: clk  +244   +0, wr  +252   +0 rd:  +243   +0
4880860758: sio_revents: revents = 0x1, took 3213ns
4880890720: sio_revents: revents = 0x0, took 1257ns
4888564391: sio_revents: revents = 0x0, took 1397ns
4888580734: sio_revents: revents = 0x0, took 1257ns
4888593725: sio_revents: revents = 0x0, took 1257ns
4888606226: sio_revents: revents = 0x0, took 1257ns
4888619077: sio_revents: revents = 0x0, took 1257ns
4888631648: sio_revents: revents = 0x0, took 1258ns
4888644290: sio_revents: revents = 0x0, took 1257ns
4888656791: sio_revents: revents = 0x0, took 1257ns
04900911841: clk  +245   +0, wr  +253   +0 rd:  +244   +0
4900910305: sio_revents: revents = 0x1, took 5308ns
4900943479: sio_revents: revents = 0x0, took 1257ns
4918553330: sio_revents: revents = 0x0, took 1397ns
4918567788: sio_revents: revents = 0x0, took 1257ns
4918580708: sio_revents: revents = 0x0, took 1257ns
4918593210: sio_revents: revents = 0x0, took 1257ns
04920863680: clk  +246   +0, wr  +254   +0 rd:  +245   +0
4920862074: sio_revents: revents = 0x1, took 5308ns
4920895667: sio_revents: revents = 0x0, took 1257ns
04940910922: clk  +247   +0, wr  +255   +0 rd:  +246   +0
4940909595: sio_revents: revents = 0x1, took 3353ns
4940939837: sio_revents: revents = 0x0, took 1187ns
4948597933: sio_revents: revents = 0x0, took 1397ns
4948612530: sio_revents: revents = 0x0, took 1257ns
4948625590: sio_revents: revents = 0x0, took 1258ns
4948638162: sio_revents: revents = 0x0, took 1257ns
4948650873: sio_revents: revents = 0x0, took 1257ns
4948663514: sio_revents: revents = 0x0, took 1187ns
4948677203: sio_revents: revents = 0x0, took 1187ns
4948689705: sio_revents: revents = 0x0, took 1257ns
04960862272: clk  +248   +0, wr  +256   +0 rd:  +247   +0
4960860736: sio_revents: revents = 0x1, took 5307ns
4960893980: sio_revents: revents = 0x0, took 1257ns
4978551672: sio_revents: revents = 0x0, took 1397ns
4978611037: sio_revents: revents = 0x0, took 1537ns
4978626263: sio_revents: revents = 0x0, took 1257ns
4978638904: sio_revents: revents = 0x0, took 1257ns
04980909444: clk  +249   +0, wr  +257   +0 rd:  +248   +0
4980907908: sio_revents: revents = 0x1, took 5378ns
4980941641: sio_revents: revents = 0x0, took 1257ns
05000862959: clk  +250   +0, wr  +258   +0 rd:  +249   +0
5000861632: sio_revents: revents = 0x1, took 3353ns
5000891734: sio_revents: revents = 0x0, took 1257ns
5008558491: sio_revents: revents = 0x0, took 1397ns
5008573088: sio_revents: revents = 0x0, took 1257ns
5008586218: sio_revents: revents = 0x0, took 1257ns
5008598859: sio_revents: revents = 0x0, took 1257ns
5008611710: sio_revents: revents = 0x0, took 1257ns
5008624282: sio_revents: revents = 0x0, took 1257ns
5008636923: sio_revents: revents = 0x0, took 1257ns
5008649354: sio_revents: revents = 0x0, took 1258ns
05020907617: clk  +251   +0, wr  +259   +0 rd:  +250   +0
5020906081: sio_revents: revents = 0x1, took 5308ns
5020939535: sio_revents: revents = 0x0, took 1187ns
5038552179: sio_revents: revents = 0x0, took 1327ns
5038566427: sio_revents: revents = 0x0, took 1257ns
5038579348: sio_revents: revents = 0x0, took 1257ns
5038591989: sio_revents: revents = 0x0, took 1257ns
05040863158: clk  +252   +0, wr  +260   +0 rd:  +251   +0
5040861621: sio_revents: revents = 0x1, took 5308ns
5040895215: sio_revents: revents = 0x0, took 1187ns
05060906628: clk  +253   +0, wr  +261   +0 rd:  +252   +0
5060905371: sio_revents: revents = 0x1, took 3283ns
5060935403: sio_revents: revents = 0x0, took 1187ns
5068562281: sio_revents: revents = 0x0, took 1396ns
5068576808: sio_revents: revents = 0x0, took 1257ns
5068589798: sio_revents: revents = 0x0, took 1257ns
5068603696: sio_revents: revents = 0x0, took 1258ns
5068616477: sio_revents: revents = 0x0, took 1188ns
5068628979: sio_revents: revents = 0x0, took 1187ns
5068641690: sio_revents: revents = 0x0, took 1187ns
5068654052: sio_revents: revents = 0x0, took 1257ns
05080862518: clk  +254   +0, wr  +262   +0 rd:  +253   +0
5080860981: sio_revents: revents = 0x1, took 5239ns
5080894156: sio_revents: revents = 0x0, took 1187ns
5098553385: sio_revents: revents = 0x0, took 1397ns
5098567563: sio_revents: revents = 0x0, took 1257ns
5098580483: sio_revents: revents = 0x0, took 1258ns
5098593055: sio_revents: revents = 0x0, took 1257ns
05100908503: clk  +255   +0, wr  +263   +0 rd:  +254   +0
5100906966: sio_revents: revents = 0x1, took 5308ns
5100940490: sio_revents: revents = 0x0, took 1187ns
05120862926: clk  +256   +0, wr  +264   +0 rd:  +255   +0
5120861599: sio_revents: revents = 0x1, took 3352ns
5120891840: sio_revents: revents = 0x0, took 1188ns
5128592680: sio_revents: revents = 0x0, took 1397ns
5128607207: sio_revents: revents = 0x0, took 1257ns
5128620197: sio_revents: revents = 0x0, took 1257ns
5128632699: sio_revents: revents = 0x0, took 1257ns
5128645550: sio_revents: revents = 0x0, took 1257ns
5128658051: sio_revents: revents = 0x0, took 1257ns
5128670902: sio_revents: revents = 0x0, took 1257ns
5128683403: sio_revents: revents = 0x0, took 1258ns
05140908981: clk  +257   +0, wr  +265   +0 rd:  +256   +0
5140907444: sio_revents: revents = 0x1, took 5308ns
5140940688: sio_revents: revents = 0x0, took 1258ns
5158513594: sio_revents: revents = 0x0, took 1327ns
5158527003: sio_revents: revents = 0x0, took 1257ns
5158539854: sio_revents: revents = 0x0, took 1257ns
5158552425: sio_revents: revents = 0x0, took 1257ns
05160863823: clk  +258   +0, wr  +266   +0 rd:  +257   +0
5160862356: sio_revents: revents = 0x1, took 5098ns
5160895391: sio_revents: revents = 0x0, took 1257ns
05180898633: clk  +259   +0, wr  +267   +0 rd:  +258   +0
5180897306: sio_revents: revents = 0x1, took 3213ns
5180927338: sio_revents: revents = 0x0, took 1257ns
5188595142: sio_revents: revents = 0x0, took 1397ns
5188609739: sio_revents: revents = 0x0, took 1257ns
5188622869: sio_revents: revents = 0x0, took 1257ns
5188635441: sio_revents: revents = 0x0, took 1257ns
5188648292: sio_revents: revents = 0x0, took 1257ns
5188660723: sio_revents: revents = 0x0, took 1257ns
5188673434: sio_revents: revents = 0x0, took 1257ns
5188685936: sio_revents: revents = 0x0, took 1257ns
05200862694: clk  +260   +0, wr  +268   +0 rd:  +259   +0
5200861158: sio_revents: revents = 0x1, took 5237ns
5200894262: sio_revents: revents = 0x0, took 1257ns
5218552513: sio_revents: revents = 0x0, took 1397ns
5218566691: sio_revents: revents = 0x0, took 1257ns
5218579681: sio_revents: revents = 0x0, took 1258ns
5218592253: sio_revents: revents = 0x0, took 1257ns
05220889542: clk  +261   +0, wr  +269   +0 rd:  +260   +0
5220888006: sio_revents: revents = 0x1, took 5308ns
5220922228: sio_revents: revents = 0x0, took 1257ns
05240863242: clk  +262   +0, wr  +270   +0 rd:  +261   +0
5240861705: sio_revents: revents = 0x1, took 4749ns
5240894181: sio_revents: revents = 0x0, took 1188ns
5248561776: sio_revents: revents = 0x0, took 1397ns
5248576094: sio_revents: revents = 0x0, took 1257ns
5248589154: sio_revents: revents = 0x0, took 1257ns
5248601726: sio_revents: revents = 0x0, took 1257ns
5248614506: sio_revents: revents = 0x0, took 1328ns
5248627148: sio_revents: revents = 0x0, took 1257ns
5248639859: sio_revents: revents = 0x0, took 1187ns
5248652291: sio_revents: revents = 0x0, took 1257ns
05260882966: clk  +263   +0, wr  +271   +0 rd:  +262   +0
5260881360: sio_revents: revents = 0x1, took 5308ns
5260914604: sio_revents: revents = 0x0, took 1257ns
5278556652: sio_revents: revents = 0x0, took 1397ns
5278571109: sio_revents: revents = 0x0, took 1257ns
5278584100: sio_revents: revents = 0x0, took 1257ns
5278596601: sio_revents: revents = 0x0, took 1257ns
05280863230: clk  +264   +0, wr  +272   +0 rd:  +263   +0
5280861694: sio_revents: revents = 0x1, took 5168ns
5280896265: sio_revents: revents = 0x0, took 1257ns
05300879044: clk  +265   +0, wr  +273   +0 rd:  +264   +0
5300877577: sio_revents: revents = 0x1, took 3981ns
5300908866: sio_revents: revents = 0x0, took 1187ns
5308595947: sio_revents: revents = 0x0, took 1466ns
5308610614: sio_revents: revents = 0x0, took 1257ns
5308623604: sio_revents: revents = 0x0, took 1257ns
5308636176: sio_revents: revents = 0x0, took 1257ns
5308648887: sio_revents: revents = 0x0, took 1257ns
5308661458: sio_revents: revents = 0x0, took 1257ns
5308674169: sio_revents: revents = 0x0, took 1257ns
5308686531: sio_revents: revents = 0x0, took 1257ns
05320862870: clk  +266   +0, wr  +274   +0 rd:  +265   +0
5320861333: sio_revents: revents = 0x1, took 5308ns
5320894718: sio_revents: revents = 0x0, took 1257ns
5338514207: sio_revents: revents = 0x0, took 1327ns
5338527686: sio_revents: revents = 0x0, took 1327ns
5338540537: sio_revents: revents = 0x0, took 1327ns
5338553178: sio_revents: revents = 0x0, took 1257ns
05340885318: clk  +267   +0, wr  +275   +0 rd:  +266   +0
5340883782: sio_revents: revents = 0x1, took 5168ns
5340916956: sio_revents: revents = 0x0, took 1397ns
05360862300: clk  +268   +0, wr  +276   +0 rd:  +267   +0
5360861043: sio_revents: revents = 0x1, took 3283ns
5360891843: sio_revents: revents = 0x0, took 1187ns
5368593590: sio_revents: revents = 0x0, took 1397ns
5368607978: sio_revents: revents = 0x0, took 1257ns
5368620968: sio_revents: revents = 0x0, took 1257ns
5368633470: sio_revents: revents = 0x0, took 1257ns
5368646321: sio_revents: revents = 0x0, took 1187ns
5368658752: sio_revents: revents = 0x0, took 1258ns
5368671463: sio_revents: revents = 0x0, took 1258ns
5368683895: sio_revents: revents = 0x0, took 1257ns
05380890964: clk  +269   +0, wr  +277   +0 rd:  +268   +0
5380889428: sio_revents: revents = 0x1, took 5238ns
5380922323: sio_revents: revents = 0x0, took 1257ns
5398554454: sio_revents: revents = 0x0, took 1396ns
5398568771: sio_revents: revents = 0x0, took 1257ns
5398581831: sio_revents: revents = 0x0, took 1257ns
5398595520: sio_revents: revents = 0x0, took 1397ns
05400864035: clk  +270   +0, wr  +278   +0 rd:  +269   +0
5400862498: sio_revents: revents = 0x1, took 5099ns
5400895673: sio_revents: revents = 0x0, took 1257ns
05420892071: clk  +271   +0, wr  +279   +0 rd:  +270   +0
5420890744: sio_revents: revents = 0x1, took 3352ns
5420921544: sio_revents: revents = 0x0, took 1257ns
5428562529: sio_revents: revents = 0x0, took 1397ns
5428576986: sio_revents: revents = 0x0, took 1257ns
5428589837: sio_revents: revents = 0x0, took 1257ns
5428602478: sio_revents: revents = 0x0, took 1258ns
5428615190: sio_revents: revents = 0x0, took 1257ns
5428627761: sio_revents: revents = 0x0, took 1187ns
5428640472: sio_revents: revents = 0x0, took 1257ns
5428652834: sio_revents: revents = 0x0, took 1257ns
05440863465: clk  +272   +0, wr  +280   +0 rd:  +271   +0
5440861928: sio_revents: revents = 0x1, took 5308ns
5440895103: sio_revents: revents = 0x0, took 1187ns
5458553284: sio_revents: revents = 0x0, took 1397ns
5458567462: sio_revents: revents = 0x0, took 1257ns
5458580453: sio_revents: revents = 0x0, took 1257ns
5458593024: sio_revents: revents = 0x0, took 1257ns
05460891221: clk  +273   +0, wr  +281   +0 rd:  +272   +0
5460889755: sio_revents: revents = 0x1, took 5168ns
5460923069: sio_revents: revents = 0x0, took 1257ns
05480862336: clk  +274   +0, wr  +282   +0 rd:  +273   +0
5480861079: sio_revents: revents = 0x1, took 3283ns
5480891181: sio_revents: revents = 0x0, took 1187ns
5488560592: sio_revents: revents = 0x0, took 1397ns
5488574840: sio_revents: revents = 0x0, took 1187ns
5488587830: sio_revents: revents = 0x0, took 1187ns
5488600262: sio_revents: revents = 0x0, took 1257ns
5488613043: sio_revents: revents = 0x0, took 1257ns
5488625544: sio_revents: revents = 0x0, took 1187ns
5488638116: sio_revents: revents = 0x0, took 1257ns
5488650827: sio_revents: revents = 0x0, took 1257ns
05500892258: clk  +275   +0, wr  +283   +0 rd:  +274   +0
5500890582: sio_revents: revents = 0x1, took 6006ns
5500924874: sio_revents: revents = 0x0, took 1257ns
5518554001: sio_revents: revents = 0x0, took 1397ns
5518568668: sio_revents: revents = 0x0, took 1257ns
5518581798: sio_revents: revents = 0x0, took 1257ns
5518594299: sio_revents: revents = 0x0, took 1257ns
05520863582: clk  +276   +0, wr  +284   +0 rd:  +275   +0
5520861906: sio_revents: revents = 0x1, took 5378ns
5520895430: sio_revents: revents = 0x0, took 1257ns
05540898113: clk  +277   +0, wr  +285   +0 rd:  +276   +0
5540896786: sio_revents: revents = 0x1, took 3422ns
5540926958: sio_revents: revents = 0x0, took 1187ns
5548595042: sio_revents: revents = 0x0, took 1397ns
5548625004: sio_revents: revents = 0x0, took 1257ns
5548638553: sio_revents: revents = 0x0, took 1187ns
5548651124: sio_revents: revents = 0x0, took 1258ns
5548663905: sio_revents: revents = 0x0, took 1257ns
5548676407: sio_revents: revents = 0x0, took 1257ns
5548688978: sio_revents: revents = 0x0, took 1257ns
5548701340: sio_revents: revents = 0x0, took 1257ns
05560863012: clk  +278   +0, wr  +286   +0 rd:  +277   +0
5560861476: sio_revents: revents = 0x1, took 5308ns
5560894790: sio_revents: revents = 0x0, took 1257ns
5578555626: sio_revents: revents = 0x0, took 1396ns
5578569943: sio_revents: revents = 0x0, took 1257ns
5578582933: sio_revents: revents = 0x0, took 1258ns
5578595505: sio_revents: revents = 0x0, took 1187ns
05580903899: clk  +279   +0, wr  +287   +0 rd:  +278   +0
5580902293: sio_revents: revents = 0x1, took 5377ns
5580935816: sio_revents: revents = 0x0, took 1257ns
05600863700: clk  +280   +0, wr  +288   +0 rd:  +279   +0
5600862303: sio_revents: revents = 0x1, took 4749ns
5600894849: sio_revents: revents = 0x0, took 1257ns
5608561746: sio_revents: revents = 0x0, took 1396ns
5608576063: sio_revents: revents = 0x0, took 1257ns
5608589054: sio_revents: revents = 0x0, took 1327ns
5608601625: sio_revents: revents = 0x0, took 1257ns
5608614336: sio_revents: revents = 0x0, took 1257ns
5608626908: sio_revents: revents = 0x0, took 1257ns
5608639619: sio_revents: revents = 0x0, took 1257ns
5608652120: sio_revents: revents = 0x0, took 1257ns
5609293752: sio_revents: revents = 0x0, took 1537ns
mplayer0 vol=127,pst=run,mmc=off,rmsg,widl: STOP message
mplayer0 vol=127,pst=run,mmc=off: stopping
05620909894: clk  +281   +0, wr  +289   +0 rd:  +280   +0
5620908288: sio_revents: revents = 0x1, took 5657ns
05640863060: clk  +282   +0, wr  +290   +0 rd:  +281   +0
5640861523: sio_revents: revents = 0x1, took 4680ns
05660916658: clk  +283   +0, wr  +291   +0 rd:  +282   +0
5660915331: sio_revents: revents = 0x1, took 3352ns
05680863608: clk  +284   +0, wr  +292   +0 rd:  +283   +0
5680862141: sio_revents: revents = 0x1, took 4889ns
05700925935: clk  +285   +0, wr  +293   +0 rd:  +284   +0
5700924678: sio_revents: revents = 0x1, took 3283ns
05720863457: clk  +286   +0, wr  +294   +0 rd:  +285   +0
5720862199: sio_revents: revents = 0x1, took 3143ns
05740926134: clk  +287   +0, wr  +295   +0 rd:  +286   +0
5740924877: sio_revents: revents = 0x1, took 3282ns
05760863934: clk  +288   +0, wr  +296   +0 rd:  +287   +0
5760862328: sio_revents: revents = 0x1, took 5028ns
05780930173: clk  +289   +0, wr  +297   +0 rd:  +288   +0
5780928916: sio_revents: revents = 0x1, took 3213ns
05800862945: clk  +290   +0, wr  +298   +0 rd:  +289   +0
5800861618: sio_revents: revents = 0x1, took 3353ns
05820933654: clk  +291   +0, wr  +299   +0 rd:  +290   +0
5820932257: sio_revents: revents = 0x1, took 3842ns
05840863493: clk  +292   +0, wr  +300   +0 rd:  +291   +0
5840862236: sio_revents: revents = 0x1, took 3282ns
05860936297: clk  +293   +0, wr  +301   +0 rd:  +292   +0
5860935110: sio_revents: revents = 0x1, took 3073ns
05880862853: clk  +294   +0, wr  +302   +0 rd:  +293   +0
5880861596: sio_revents: revents = 0x1, took 3143ns
mplayer0 vol=127,pst=ini,mmc=off,rmsg,widl: stopped
5880875075: sio_revents: revents = 0x0, took 1258ns
mplayer0 vol=127,pst=ini,mmc=off,rmsg,widl: building STOP message
5880896098: sio_revents: revents = 0x0, took 1327ns
mplayer0 vol=127,pst=ini,mmc=off,rmsg,widl: BYE message
mplayer0 vol=127,pst=ini,mmc=off,rmsg,widl: closing
snd0 pst=run: device released
sock(sock|zom): destroyed
05900944457: clk  +295   +0, wr  +303   +0 rd:  +294   +0
5900942781: sio_revents: revents = 0x1, took 6425ns
libsndio: polls: 1592, samples = 283200
snd0 pst=run: device stopped
snd0 pst=run: stopped, load avg = 23604 / 5877349
snd0 pst=ini: closing
snd0 pst=cfg: closed
sio(rsnd/0|zom): destroyed
listen(/tmp/aucat-1000/aucat0|zom): destroyed
snd0 pst=cfg: draining
nothing to do...
snd0 pst=cfg: deleting