Seeing avcodec errors when playing video #1346

totaam · 2016-10-26T01:18:13Z

Issue migrated from trac ticket # 1346

component: server | priority: major | resolution: fixed

2016-10-26 01:18:13: afarr created the issue

1.0 r14155 osx client and 1.0 r14282 fedora 23 server.

While playing video (html5 and flash, in case that might make a difference) I'm regularly seeing an avcodec error (starts usually within 1-2 minutes of the video starting (though it sometimes feels like 5 long minutes).

Client-side:

2016-10-25 17:15:30,108 Error: avcodec error -35 decoding 7928 bytes of h264 data:
2016-10-25 17:15:30,109  'Resource temporarily unavailable'
2016-10-25 17:15:30,109  frame 0
2016-10-25 17:15:30,109  options={'pts': 0, 'encoding': 'h264', 'type': 'IDR', 'frame': 0, 'delayed': 1, 'csc': 'YUV420P', 'paint': False, 'flush': 0, 'quality': 60, 'speed': 73}
2016-10-25 17:15:30,110  decoder state:
2016-10-25 17:15:30,110   decoder_height = 360
2016-10-25 17:15:30,110   encoding = h264
2016-10-25 17:15:30,110   colorspace = YUV420P
2016-10-25 17:15:30,110   actual_colorspace = YUV420P
2016-10-25 17:15:30,111   height = 360
2016-10-25 17:15:30,111   decoder_width = 640
2016-10-25 17:15:30,111   width = 640
2016-10-25 17:15:30,112   version = (57, 48, 101)
2016-10-25 17:15:30,112   formats = ['YUV422P', 'BGRX', 'GBRP', 'RGB', 'YUV420P', 'BGRA', 'ARGB', 'XRGB', 'YUV444P']
2016-10-25 17:15:30,114   frames = 0
2016-10-25 17:15:30,114   type = avcodec

The text was updated successfully, but these errors were encountered:

totaam · 2016-10-26T02:20:48Z

2016-10-26 02:20:48: afarr commented

Testing for #1135, with -d stats,x264,compress on the server, I think I've spotted the cause of this being the initialization of an x264 context encoding YUV420P frames (or it's just a coincidence?).

Doing a short test, I see two x264 contexts initialized, one encoding BGRX frames, the other YUV420P. Immediately after the intitialization of the YUV 420P context, I see the above error.

2016-10-25 18:02:49,513 x264 close context 0x7fbd700671c0
2016-10-25 18:02:49,530 x264 close context 0x0
2016-10-25 18:02:49,531 using default profile=high444
2016-10-25 18:02:49,539 x264 context=0x7fbd700671c0,    BGRX  768x432  quality=59, speed=94, source=unknown
2016-10-25 18:02:49,539  preset=superfast, profile=high444, tune=zerolatency
2016-10-25 18:02:49,540  me=DIA, me_range=16, mv_range=-1, b-frames=0, max delayed frames=0
2016-10-25 18:02:49,540  vfr-input=0, lookahead=-1, sync-lookahead=0, mb-tree=0, bframe-adaptive=FAST
2016-10-25 18:02:49,540  threads=auto, sliced-threads=True
2016-10-25 18:02:49,553 x264 encode    BGRX frame     0 as  IDR slice with 7 nals, tune=zerolatency, total   50431 bytes, keyframe=True , delayed=0
2016-10-25 18:02:49,554 compress:  23.3ms for  768x432  pixels at   69,320  for wid=3     using  h264 with ratio   3.8% ( 1296KB to    49KB), client_options={'pts': 0, 'frame': 0L, 'flush': 0, 'csc': 'YUV444P', 'type': 'IDR', 'quality': 59, 'speed': 94}
2016-10-25 18:02:49,561 client 1: process_draw:   50431    bytes for window   3 using   h264 encoding with options={'speed': 94, 'type': 'IDR', 'flush': 0, 'pts': 0, 'frame': 0, 'quality': 59, 'csc': 'YUV444P'}
2016-10-25 18:02:49,574 packet decoding sequence 690 for window 3: 768x432 took 13.4ms
2016-10-25 18:02:49,575 record_latency: took   20.6 ms round trip,   20.4 for echo,   13.0 for decoding of   331776 pixels,    50530 bytes sent over the network in    7.2 ms,    7.1 ms for echo
2016-10-25 18:02:49,575 may_recalculate(3, 331776) total 331776 pixels, scheduling recalculate work item

...

2016-10-25 18:02:50,554 x264 close context 0x0
2016-10-25 18:02:50,565 x264 context=0x7fbd700671c0, YUV420P  768x432  quality=55, speed=94, source=video
2016-10-25 18:02:50,566  preset=superfast, profile=high10, tune=film
2016-10-25 18:02:50,566  me=DIA, me_range=16, mv_range=-1, b-frames=1, max delayed frames=1
2016-10-25 18:02:50,566  vfr-input=0, lookahead=0, sync-lookahead=-1, mb-tree=0, bframe-adaptive=FAST
2016-10-25 18:02:50,566  threads=auto, sliced-threads=True
2016-10-25 18:02:50,573 x264 encode 1 delayed frames after 0
2016-10-25 18:02:50,579 compress:  24.3ms for  768x432  pixels at   69,320  for wid=3     using  jpeg with ratio   4.8% ( 1296KB to    61KB), client_options={'quality': 95, 'flush': 0}
2016-10-25 18:02:50,588 client 1: process_draw:   63444    bytes for window   3 using   jpeg encoding with options={'quality': 95, 'flush': 0}
2016-10-25 18:02:50,595 packet decoding sequence 713 for window 3: 768x432 took 7.0ms
2016-10-25 18:02:50,596 record_latency: took   16.6 ms round trip,   16.5 for echo,    6.0 for decoding of   331776 pixels,    63502 bytes sent over the network in    9.6 ms,    9.5 ms for echo
2016-10-25 18:02:50,614 x264 encode YUV420P frame     0 as  IDR slice with 7 nals, tune=film, total   23083 bytes, keyframe=True , delayed=1
2016-10-25 18:02:50,615 compress:  13.6ms for  768x432  pixels at   69,320  for wid=3     using  h264 with ratio   1.7% ( 1296KB to    22KB), client_options={'pts': 0, 'frame': 0L, 'flush': 0, 'delayed': 1, 'csc': 'YUV420P', 'paint': False, 'type': 'IDR', 'quality': 55, 'speed': 94}
2016-10-25 18:02:50,625 client 1: process_draw:   23083    bytes for window   3 using   h264 encoding with options={'pts': 0, 'type': 'IDR', 'frame': 0, 'delayed': 1, 'csc': 'YUV420P', 'paint': False, 'flush': 0, 'quality': 55, 'speed': 94}
2016-10-25 18:02:50,627 client 1: Error: avcodec error -35 decoding 23083 bytes of h264 data:
2016-10-25 18:02:50,627 client 1:  'Resource temporarily unavailable'
2016-10-25 18:02:50,628 client 1:  frame 0
2016-10-25 18:02:50,629 client 1:  options={'pts': 0, 'encoding': 'h264', 'type': 'IDR', 'frame': 0, 'delayed': 1, 'csc': 'YUV420P', 'paint': False, 'flush': 0, 'quality': 55, 'speed': 94}
2016-10-25 18:02:50,629 client 1:  decoder state:
2016-10-25 18:02:50,629 client 1:   decoder_height = 432
2016-10-25 18:02:50,630 client 1:   encoding = h264
2016-10-25 18:02:50,630 client 1:   colorspace = YUV420P
2016-10-25 18:02:50,631 client 1:   actual_colorspace = YUV420P
2016-10-25 18:02:50,632 client 1:   height = 432
2016-10-25 18:02:50,633 client 1:   decoder_width = 768
2016-10-25 18:02:50,633 packet decoding sequence 714 for window 3: 768x432 took 11.1ms
2016-10-25 18:02:50,634 record_latency: took   18.7 ms round trip,   18.6 for echo,   11.0 for decoding of   331776 pixels,    23198 bytes sent over the network in    7.6 ms,    7.5 ms for echo
2016-10-25 18:02:50,634 client 1:   width = 768
2016-10-25 18:02:50,635 client 1:   version = (57, 48, 101)
2016-10-25 18:02:50,635 client 1:   formats = ['YUV422P', 'BGRX', 'GBRP', 'RGB', 'YUV420P', 'BGRA', 'ARGB', 'XRGB', 'YUV444P']
2016-10-25 18:02:50,636 client 1:   frames = 0
2016-10-25 18:02:50,636 client 1:   type = avcodec
2016-10-25 18:02:50,667 x264 encode YUV420P frame     1 as    P slice with 4 nals, tune=film, total    4626 bytes, keyframe=False, delayed=1

I don't suppose there's much point in posting this to #1135 though.

totaam · 2016-10-26T09:07:10Z

2016-10-26 09:07:10: antoine changed owner from antoine to afarr

totaam · 2016-10-26T09:07:10Z

2016-10-26 09:07:10: antoine edited the issue description

totaam · 2016-10-26T09:07:10Z

2016-10-26 09:07:10: antoine commented

I'm not sure what's happening here, I cannot reproduce it.
The YUV420P context replaces the BGRX one when the heuristics have decided that this is "real video" and therefore should be encoded as such. (#800, #1135)
I suspect that the problem may well go away if you run with XPRA_B_FRAMES=0.
It could be related to the client's capabilities, in particular how many CPU / threads are available.
Does it help if you run the server with: XPRA_X264_THREADS=1 and XPRA_X264_SLICED_THREADS=0? (and keeping b-frames enabled)

totaam · 2016-10-27T00:48:55Z

2016-10-27 00:48:55: afarr changed owner from afarr to antoine

totaam · 2016-10-27T00:48:55Z

2016-10-27 00:48:55: afarr commented

The short answer is no. Nothing seems to be making a difference. Maybe it's just my client?

I tried with XPRA_B_FRAMES=0, with XPRA_X264_THREADS=1 and XPRA_X264_SLICED_THREADS=0, with and without forcing opengl, with video, and with just scrolling text. In every case, it looks like I'm seeing this issue corresponding with an x264 context being created with tune=film.

In the case of trying with XPRA_X264_THREADS=1 and XPRA_X264_SLICED_THREADS=0, I'm also seeing a new error... which is far more regular than this avcodec error, but does still coexist.

2016-10-26 13:51:12,719 error processing encode queue at index 0
2016-10-26 13:51:12,719 item=(1310, 777, 1477515072.592879, 1477515072.690525, XShmImageWrapper(BGRX: 0, 0, 1310, 777), 'auto', 47, {}, 0)
Traceback (most recent call last):
  File "/usr/lib64/python2.7/site-packages/xpra/server/window/window_video_source.py", line 823, in encode_from_queue
    self.make_data_packet_cb(*item)
  File "/usr/lib64/python2.7/site-packages/xpra/server/window/window_source.py", line 1448, in make_data_packet_cb
    packet = self.make_data_packet(damage_time, process_damage_time, image, coding, sequence, options, flush)
  File "/usr/lib64/python2.7/site-packages/xpra/server/window/window_source.py", line 1794, in make_data_packet
    ret = encoder(coding, image, options)
  File "/usr/lib64/python2.7/site-packages/xpra/server/window/window_video_source.py", line 1467, in video_encode
    return self.do_video_encode(encoding, image, options)
  File "/usr/lib64/python2.7/site-packages/xpra/server/window/window_video_source.py", line 1568, in do_video_encode
    ret = ve.compress_image(csc_image, quality, speed, options)
  File "xpra/codecs/enc_x264/encoder.pyx", line 717, in xpra.codecs.enc_x264.encoder.Encoder.compress_image (xpra/codecs/enc_x264/encoder.c:7846)
  File "xpra/codecs/enc_x264/encoder.pyx", line 750, in xpra.codecs.enc_x264.encoder.Encoder.do_compress_image (xpra/codecs/enc_x264/encoder.c:8408)
Exception: x264_encoder_encode produced no data!
2016-10-26 13:51:55,572 client 1: UI thread is now blocked
2016-10-26 13:51:55,576 client 1: UI thread is running again, resuming
2016-10-26 13:51:55,729 Error during encoding:
Traceback (most recent call last):
  File "/usr/lib64/python2.7/site-packages/xpra/server/source.py", line 2185, in encode_loop
    fn_and_args[1](*fn_and_args[2:])
  File "/usr/lib64/python2.7/site-packages/xpra/server/window/window_source.py", line 1448, in make_data_packet_cb
    packet = self.make_data_packet(damage_time, process_damage_time, image, coding, sequence, options, flush)
  File "/usr/lib64/python2.7/site-packages/xpra/server/window/window_source.py", line 1794, in make_data_packet
    ret = encoder(coding, image, options)
  File "/usr/lib64/python2.7/site-packages/xpra/server/window/window_video_source.py", line 1467, in video_encode
    return self.do_video_encode(encoding, image, options)
  File "/usr/lib64/python2.7/site-packages/xpra/server/window/window_video_source.py", line 1568, in do_video_encode
    ret = ve.compress_image(csc_image, quality, speed, options)
  File "xpra/codecs/enc_x264/encoder.pyx", line 717, in xpra.codecs.enc_x264.encoder.Encoder.compress_image (xpra/codecs/enc_x264/encoder.c:7846)
  File "xpra/codecs/enc_x264/encoder.pyx", line 750, in xpra.codecs.enc_x264.encoder.Encoder.do_compress_image (xpra/codecs/enc_x264/encoder.c:8408)
Exception: x264_encoder_encode produced no data!

I can attach some clips of logs but the short bit is that it looks like whenever the x264 is tune=zerolatency I'm not seeing the avcodec error, whether it is YUV444, YUV420, or BGRX, but when I triggered tune=film (just by pasting a pile of logs into a gedit window and then scrolling a lot), then I see the error logs:

2016-10-26 16:18:00,837 x264 context=0x7f3d98015e80, YUV420P  762x460  quality=44, speed=74, source=video
2016-10-26 16:18:00,837  preset=faster, profile=high10, tune=film
2016-10-26 16:18:00,838  me=HEX, me_range=16, mv_range=-1, b-frames=1, max delayed frames=1
2016-10-26 16:18:00,838  vfr-input=0, lookahead=0, sync-lookahead=-1, mb-tree=1, bframe-adaptive=FAST
2016-10-26 16:18:00,839  threads=auto, sliced-threads=True
2016-10-26 16:18:00,849 x264 encode 1 delayed frames after 0
2016-10-26 16:18:00,862 compress:  36.2ms for 1145x690  pixels at    5,5    for wid=3     using  jpeg with ratio   6.9% ( 3086KB to   211KB), client_options={'quality': 84, 'flush': 0}
2016-10-26 16:18:00,912 x264 encode YUV420P frame     0 as  IDR slice with 7 nals, tune=film, total   33747 bytes, keyframe=True , delayed=1
2016-10-26 16:18:00,913 compress:  22.5ms for 1144x690  pixels at    5,5    for wid=3     using  h264 with ratio   1.1% ( 3086KB to    32KB), client_options={'scaled_size': (762, 460), 'pts': 0, 'frame': 0L, 'flush': 0, 'delayed': 1, 'csc': 'YUV420P', 'paint': False, 'type': 'IDR', 'quality': 44, 'speed': 74}
2016-10-26 16:18:00,919 packet decoding sequence 230 for window 3: 1145x690 took 21.4ms
2016-10-26 16:18:00,920 record_latency: took   54.9 ms round trip,   54.7 for echo,   21.0 for decoding of   790050 pixels,   216985 bytes sent over the network in   33.5 ms,   33.4 ms for echo
2016-10-26 16:18:00,920 may_recalculate(3, 790050) total 790050 pixels, scheduling recalculate work item
2016-10-26 16:18:00,928 client 1: Error: avcodec error -35 decoding 33747 bytes of h264 data:
2016-10-26 16:18:00,928 client 1:  'Resource temporarily unavailable'
2016-10-26 16:18:00,928 client 1:  frame 0
2016-10-26 16:18:00,929 client 1:  options={'pts': 0, 'scaled_size': (762, 460), 'type': 'IDR', 'frame': 0, 'encoding': 'h264', 'delayed': 1, 'csc': 'YUV420P', 'paint': False, 'flush': 0, 'quality': 44, 'speed': 74}
2016-10-26 16:18:00,931 client 1:  decoder state:
2016-10-26 16:18:00,931 client 1:   decoder_height = 460
2016-10-26 16:18:00,932 packet decoding sequence 231 for window 3: 1144x690 took 9.7ms
2016-10-26 16:18:00,932 record_latency: took   17.7 ms round trip,   17.6 for echo,    9.0 for decoding of   789360 pixels,    33878 bytes sent over the network in    8.1 ms,    8.0 ms for echo
2016-10-26 16:18:00,932 client 1:   encoding = h264
2016-10-26 16:18:00,933 client 1:   colorspace = YUV420P
2016-10-26 16:18:00,933 client 1:   actual_colorspace = YUV420P
2016-10-26 16:18:00,933 client 1:   height = 460
2016-10-26 16:18:00,934 client 1:   decoder_width = 762
2016-10-26 16:18:00,934 client 1:   width = 762
2016-10-26 16:18:00,934 client 1:   version = (57, 48, 101)
2016-10-26 16:18:00,935 client 1:   formats = ['YUV422P', 'BGRX', 'GBRP', 'RGB', 'YUV420P', 'BGRA', 'ARGB', 'XRGB', 'YUV444P']
2016-10-26 16:18:00,935 client 1:   frames = 0
2016-10-26 16:18:00,935 client 1:   type = avcodec

totaam · 2016-10-27T06:47:55Z

2016-10-27 06:47:55: antoine changed status from new to assigned

totaam · 2016-10-27T06:47:55Z

2016-10-27 06:47:55: antoine commented

I think I can reproduce it, but not very reliably.

Adding better debug logging in r14295 + r14296 and running the server with "-d compress,x264" the client with "-d avcodec", it seems that we're cleaning the video context before the last frame is received:

server shows:

compress:  16.3ms for 1236x612  pixels at    5,53   for wid=2     using  h264 with ratio   1.2% ( 2957KB to    36KB), sequence= 2372, client_options=\
    {'pts': 1896, 'frame': 33L, 'flush': 0, 'csc': 'YUV420P', 'scaled_size': (824, 408), 'type': 'P', 'quality': 87, 'speed': 86}
compress:  41.4ms for 1236x612  pixels at    5,53   for wid=2     using  h264 with ratio   1.1% ( 2957KB to    33KB), sequence= 2373, client_options=\
    {'pts': 1937, 'frame': 34L, 'flush': 0, 'csc': 'YUV420P', 'type': 'P', 'quality': 86, 'speed': 86}
setup_pipeline: trying (82, (1, 3), (1, 3), 1236, 612, video_spec(libyuv), 'YUV420P', (1, 1), 412, 204, video_spec(x264))

client shows:

decompress_image(<type 'str'>:37088, \
    {'pts': 1896, 'encoding': 'h264', 'type': 'P', 'frame': 33, 'csc': 'YUV420P', \
     'scaled_size': (824, 408), 'flush': 0, 'quality': 87, 'speed': 86}
    )=AVImageWrapper-AVFrameWrapper(0x7fc844006e00)(YUV420P:(0, 0, 824, 408, 24):3_PLANES)
(..)
clean_decoder() freeing AVCodecContext: 0x7fc844001b00
(..)
Error: avcodec error -1094995529 decoding 33842 bytes of h264 data:
(..)
frame options={'speed': 86, 'type': 'P', 'flush': 0, 'pts': 1937, 'frame': 34, 'encoding': 'h264', 'quality': 86, 'csc': 'YUV420P'}

Frame 34 should have been decoded with the same context as 33.

The bad news is that I have no idea why this happens.
The good news is that the decoder just drops this "corrupt" frame and carries on.

totaam · 2016-10-27T10:26:21Z

2016-10-27 10:26:21: antoine changed status from assigned to new

totaam · 2016-10-27T10:26:21Z

2016-10-27 10:26:21: antoine changed owner from antoine to afarr

totaam · 2016-10-27T10:26:21Z

2016-10-27 10:26:21: antoine commented

Logging the client with "-d paint,-opengl", I can see:
draw_region(5, 53, 1236, 612, h264, 43416 bytes, 0, \
    {'pts': 939, 'type': 'P', 'frame': 45, 'delayed': 1, 'csc': 'YUV420P', \
     'scaled_size': (824, 408), 'flush': 0, 'quality': 93, 'speed': 78}, \
    [<function record_decode_time at 0x7fcaaf1cf050>, <function after_draw_refresh at 0x7fcaac24db90>])
paint_with_video_decoder: window dimensions have changed from (824, 408) to (1236, 612)
draw_region(5, 53, 1236, 612, h264, 35868 bytes, 0, \
    {'type': 'B', 'pts': 922, 'frame': 46, 'delayed': 1, 'csc': 'YUV420P', \
     'flush': 0, 'quality': 93, 'speed': 78}, \
    [<function record_decode_time at 0x7fcaaf1cf050>, <function after_draw_refresh at 0x7fcaac24db90>])
Just before the error, we are changing from scaled to unscaled video and so the client will re-create the context for the new dimensions received.
After a lot of digging, I fixed the following issues and I seem to be unable to reproduce the problem anymore:

r14298: don't forget to include the cached "scaled_size" attribute when flushing b-frames

r14301: always clean both csc and encoder at the same time (could be backported)

The problem is that these bugs are quite hard to trigger as they require very specific circumstances to fire, so I am not 100% sure that this fixed in all cases.

If you still see the Exception: x264_encoder_encode produced no data bug with XPRA_X264_THREADS=1 and XPRA_X264_SLICED_THREADS=0, please file a separate ticket for that - I'm not seeing this one at all. (but then again, I'm notoriously bad at reproducing bugs..)
The error message should be improved for that one too now.

totaam · 2016-11-02T00:40:29Z

2016-11-02 00:40:29: afarr changed owner from afarr to antoine

totaam · 2016-11-02T00:40:29Z

2016-11-02 00:40:29: afarr commented

It is a lot harder to induce testing with 1.0 14304 fedora 23 server, but ... just as I was about to give up on it... I found it again (with either 1.0 r13977 or r14155 osx clients).

I'm not seeing the 'scaled_size' window dimensions changing issues you mentioned (which suggests that was probably causing most of those previously ubiquitous errors, and is fixed), but I do notice in the cases I spotted, the errors followed closely after a paint_with_video_decoder: colorspace changed from YUV444P to YUV420P message (perhaps more than coincidence?).

With the r13977 client (not that it probably matters what client, but I saw it with both, so its two samples of logs to compare)... running with -d stat,compress,x264 server side and -d paint,opengl client side (which seem to be getting passed through to the server, so I'll just paste server log bits). ... Note, to repro I just start some video and then mouse around & maybe scroll up and down for a minute or two... maybe three... and watch for red in the log output.

2016-11-01 17:12:12,593 x264 encode YUV420P frame     0 as  IDR slice with 7 nals, tune=film, total    6905 bytes, keyframe=True , delayed=1
2016-11-01 17:12:12,594 compress:  22.0ms for  854x480  pixels at  146,150  for wid=3     using  h264 with ratio   0.4% ( 1601KB to     6KB), sequence   220, client_options={'pts': 0, 'frame': 0, 'delayed': 1, 'csc': 'YUV420P', 'paint': False, 'type': 'IDR', 'quality': 42, 'speed': 81}
2016-11-01 17:12:12,641 client 4: process_draw 6905 bytes for window 3 using h264 encoding with options={'pts': 0, 'type': 'IDR', 'frame': 0, 'delayed': 1, 'csc': 'YUV420P', 'paint': False, 'quality': 42, 'speed': 81}
2016-11-01 17:12:12,642 client 4: draw_region(146, 150, 854, 480, h264, 6905 bytes, 0, {'pts': 0, 'type': 'IDR', 'frame': 0, 'delayed': 1, 'csc': 'YUV420P', 'paint': False, 'quality': 42, 'speed': 81}, [<function record_decode_time at 0x116dfef0>, <function after_draw_refresh at 0x116dfe70>])
2016-11-01 17:12:12,642 client 4: paint_with_video_decoder: colorspace changed from YUV444P to YUV420P
2016-11-01 17:12:12,642 client 4: paint_with_video_decoder: new <type 'xpra.codecs.dec_avcodec2.decoder.Decoder'>(854,480,YUV420P)
2016-11-01 17:12:12,646 client 4: paint_with_video_decoder: info={'decoder_height': 480, 'encoding': 'h264', 'colorspace': 'YUV420P', 'actual_colorspace': 'YUV420P', 'height': 480, 'decoder_width': 854, 'width': 854, 'version': (57, 48, 101), 'formats': ['YUV422P', 'BGRX', 'GBRP', 'RGB', 'YUV420P', 'BGRA', 'ARGB', 'XRGB', 'YUV444P'], 'frames': 0L, 'type': 'avcodec'}
2016-11-01 17:12:12,647 client 4: Error: avcodec error -35 decoding 6905 bytes of h264 data:
2016-11-01 17:12:12,647 client 4:  'Resource temporarily unavailable'
2016-11-01 17:12:12,647 client 4:  frame 0
2016-11-01 17:12:12,648 client 4:  options={'pts': 0, 'encoding': 'h264', 'type': 'IDR', 'frame': 0, 'delayed': 1, 'csc': 'YUV420P', 'paint': False, 'quality': 42, 'speed': 81}
2016-11-01 17:12:12,649 client 4:  decoder state:
2016-11-01 17:12:12,649 client 4:   decoder_height = 480
2016-11-01 17:12:12,650 client 4:   encoding = h264
2016-11-01 17:12:12,650 client 4:   colorspace = YUV420P
2016-11-01 17:12:12,650 packet decoding sequence 220 for window 3: 854x480 took 8.4ms
2016-11-01 17:12:12,650 record_latency: took   55.4 ms round trip,   55.3 for echo,    8.0 for decoding of   409920 pixels,     7013 bytes sent over the network in   46.9 ms,   46.8 ms for echo
2016-11-01 17:12:12,651 client 4:   actual_colorspace = YUV420P
2016-11-01 17:12:12,651 client 4:   height = 480
2016-11-01 17:12:12,651 client 4:   decoder_width = 854
2016-11-01 17:12:12,651 client 4:   width = 854
2016-11-01 17:12:12,651 client 4:   version = (57, 48, 101)
2016-11-01 17:12:12,652 client 4:   formats = ['YUV422P', 'BGRX', 'GBRP', 'RGB', 'YUV420P', 'BGRA', 'ARGB', 'XRGB', 'YUV444P']
2016-11-01 17:12:12,652 client 4:   frames = 0
2016-11-01 17:12:12,653 client 4:   type = avcodec
2016-11-01 17:12:12,653 client 4: record_decode_time(True, ) wid=3, h264: 854x480, 8.4ms
2016-11-01 17:12:12,653 client 4: after_draw_refresh(True, ) 854x480 at 146x150 encoding=h264, options={'pts': 0, 'encoding': 'h264', 'type': 'IDR', 'frame': 0, 'delayed': 1, 'csc': 'YUV420P', 'paint': False, 'quality': 42, 'speed': 81}
2016-11-01 17:12:12,662 x264 encode YUV420P frame     1 as    P slice with 4 nals, tune=film, total    1206 bytes, keyframe=False, delayed=1
2016-11-01 17:12:12,662 compress:  16.1ms for  854x480  pixels at  146,150  for wid=3     using  h264 with ratio   0.1% ( 1601KB to     1KB), sequence   221, client_options={'pts': 144, 'frame': 1, 'delayed': 1, 'csc': 'YUV420P', 'type': 'P', 'quality': 42, 'speed': 81}
2016-11-01 17:12:12,700 client 4: process_draw 1206 bytes for window 3 using h264 encoding with options={'speed': 81, 'type': 'P', 'pts': 144, 'frame': 1, 'quality': 42, 'delayed': 1, 'csc': 'YUV420P'}
2016-11-01 17:12:12,702 client 4: draw_region(146, 150, 854, 480, h264, 1206 bytes, 0, {'speed': 81, 'type': 'P', 'pts': 144, 'frame': 1, 'quality': 42, 'delayed': 1, 'csc': 'YUV420P'}, [<function record_decode_time at 0x116dfef0>, <function after_draw_refresh at 0x116dfe70>])
2016-11-01 17:12:12,703 client 4: gl_paint_planar(0, 'h264', AVImageWrapper-None(YUV420P:(0, 0, 854, 480, 24):3_PLANES), 146, 150, 854, 480, 854, 480, [<function record_decode_time at 0x116dfef0>, <function after_draw_refresh at 0x116dfe70>])
2016-11-01 17:12:12,703 client 4: gtk2.GLWindowBacking(3, (1587, 749), GBRP).gl_context() GL Pixmap backing size: 1587 x 749, context=gtk2.GLContextManager(<gtk.DrawingArea object at 0x9f444b8 (GtkDrawingArea at 0x41b2bd8)>)
2016-11-01 17:12:12,705 client 4: gtk2.GLWindowBacking(3, (1587, 749), GBRP).update_planar_textures(146, 150, 854, 480, AVImageWrapper-None(YUV420P:(0, 0, 854, 480, 24):3_PLANES), 'YUV420P')
2016-11-01 17:12:12,705 client 4: Creating new planar textures, pixel format YUV420P
2016-11-01 17:12:12,706 client 4: updating planar textures: 854x480 YUV420P
2016-11-01 17:12:12,706 client 4: texture 0: div=(1, 1), rowstride=896, 854x480, data=430080 bytes, upload=zerocopy:buffer-as-memoryview
2016-11-01 17:12:12,706 client 4: texture 1: div=(2, 2), rowstride=448, 427x240, data=107520 bytes, upload=zerocopy:buffer-as-memoryview
2016-11-01 17:12:12,707 client 4: texture 2: div=(2, 2), rowstride=448, 427x240, data=107520 bytes, upload=zerocopy:buffer-as-memoryview
2016-11-01 17:12:12,707 client 4: gtk2.GLWindowBacking(3, (1587, 749), YUV420P).render_planar_update(146, 150, 854, 480, 1, 1) pixel_format=YUV420P
2016-11-01 17:12:12,707 client 4: painting planar update, format YUV420P
2016-11-01 17:12:12,708 client 4: gtk2.GLWindowBacking(3, (1587, 749), YUV420P).render_planar_update(..) texture_size=(854, 480), size=(1587, 749)
2016-11-01 17:12:12,708 client 4: present_fbo: adding (146, 150, 854, 480) to pending paint list (size=0), flush=0, paint_screen=True
2016-11-01 17:12:12,711 client 4: Presenting FBO on screen
2016-11-01 17:12:12,711 client 4: Switching to RGB paint state
2016-11-01 17:12:12,711 client 4: do_present_fbo: painting [(146, 150, 854, 480)]
2016-11-01 17:12:12,712 client 4: gtk2.GLWindowBacking(3, (1587, 749), YUV420P).gl_show() flushing
2016-11-01 17:12:12,712 client 4: gl_show after 125ms took  1ms,  1 updates
2016-11-01 17:12:12,713 client 4: gtk2.GLWindowBacking(3, (1587, 749), YUV420P).gl_frame_terminator()
2016-11-01 17:12:12,713 client 4: Switching back to YUV paint state
2016-11-01 17:12:12,714 client 4: <OpenGL.platform.baseplatform.glBindFramebuffer object at 0xa4d8530>(GL_FRAMEBUFFER (36160), c_ulong(1L))
2016-11-01 17:12:12,715 client 4: gtk2.GLWindowBacking(3, (1587, 749), YUV420P).do_present_fbo() done
2016-11-01 17:12:12,716 client 4: record_decode_time(True, ) wid=3, h264: 854x480, 12.2ms
2016-11-01 17:12:12,716 packet decoding sequence 221 for window 3: 854x480 took 12.2ms
2016-11-01 17:12:12,716 record_latency: took   53.3 ms round trip,   53.2 for echo,   12.0 for decoding of   409920 pixels,     1307 bytes sent over the network in   41.1 ms,   41.0 ms for echo
2016-11-01 17:12:12,717 client 4: after_draw_refresh(True, ) 854x480 at 146x150 encoding=h264, options={'speed': 81, 'type': 'P', 'pts': 144, 'frame': 1, 'encoding': 'h264', 'quality': 42, 'delayed': 1, 'csc': 'YUV420P'}

And more of nearly the same with the r14155 client:

2016-11-01 17:22:16,566 x264 close context 0x7f22bc01c520
2016-11-01 17:22:16,592 x264 close context 0x0
2016-11-01 17:22:16,603 x264 context=0x7f22bc01c520, YUV420P  764x482  quality=52, speed=62, source=video
2016-11-01 17:22:16,604  preset=faster, profile=high10, tune=film
2016-11-01 17:22:16,604  me=HEX, me_range=16, mv_range=-1, b-frames=1, max delayed frames=1
2016-11-01 17:22:16,604  vfr-input=0, lookahead=0, sync-lookahead=-1, mb-tree=1, bframe-adaptive=FAST
2016-11-01 17:22:16,604  threads=auto, sliced-threads=True
2016-11-01 17:22:16,606 client 6: draw_region(146, 150, 764, 482, h264, 4075 bytes, 0, {'speed': 63, 'csc': 'YUV444P', 'type': 'P', 'frame': 31, 'quality': 50, 'pts': 1908}, [<function record_decode_time at 0x11738770>, <function after_draw_refresh at 0x9f1ea70>])
2016-11-01 17:22:16,607 client 6: gl_paint_planar(0, 'h264', AVImageWrapper-None(GBRP:(0, 0, 764, 482, 24):3_PLANES), 146, 150, 764, 482, 764, 482, [<function record_decode_time at 0x11738770>, <function after_draw_refresh at 0x9f1ea70>])
2016-11-01 17:22:16,608 client 6: gtk2.GLWindowBacking(3, (1587, 749), GBRP).gl_context() GL Pixmap backing size: 1587 x 749, context=gtk2.GLContextManager(<gtk.DrawingArea object at 0xa84e328 (GtkDrawingArea at 0xc48bd8)>)
2016-11-01 17:22:16,608 client 6: gtk2.GLWindowBacking(3, (1587, 749), GBRP).update_planar_textures(146, 150, 764, 482, AVImageWrapper-None(GBRP:(0, 0, 764, 482, 24):3_PLANES), 'GBRP')
2016-11-01 17:22:16,609 client 6: updating planar textures: 764x482 GBRP
2016-11-01 17:22:16,610 client 6: texture 0: div=(1, 1), rowstride=768, 764x482, data=370176 bytes, upload=zerocopy:buffer-as-memoryview
2016-11-01 17:22:16,610 client 6: texture 1: div=(1, 1), rowstride=768, 764x482, data=370176 bytes, upload=zerocopy:buffer-as-memoryview
2016-11-01 17:22:16,610 client 6: texture 2: div=(1, 1), rowstride=768, 764x482, data=370176 bytes, upload=zerocopy:buffer-as-memoryview
2016-11-01 17:22:16,611 client 6: gtk2.GLWindowBacking(3, (1587, 749), GBRP).render_planar_update(146, 150, 764, 482, 1, 1) pixel_format=GBRP
2016-11-01 17:22:16,612 client 6: painting planar update, format GBRP
2016-11-01 17:22:16,612 x264 encode 1 delayed frames after 0
2016-11-01 17:22:16,618 client 6: gtk2.GLWindowBacking(3, (1587, 749), GBRP).render_planar_update(..) texture_size=(764, 482), size=(1587, 749)
2016-11-01 17:22:16,619 client 6: present_fbo: adding (146, 150, 764, 482) to pending paint list (size=0), flush=0, paint_screen=True
2016-11-01 17:22:16,619 client 6: Presenting FBO on screen
2016-11-01 17:22:16,619 client 6: Switching to RGB paint state
2016-11-01 17:22:16,619 client 6: do_present_fbo: painting [(146, 150, 764, 482)]
2016-11-01 17:22:16,620 client 6: gtk2.GLWindowBacking(3, (1587, 749), GBRP).gl_show() flushing
2016-11-01 17:22:16,619 compress:  26.1ms for  764x483  pixels at  146,150  for wid=3     using  jpeg with ratio   2.5% ( 1441KB to    36KB), sequence   916, client_options={'quality': 92}
2016-11-01 17:22:16,621 client 6: gl_show after  64ms took  0ms,  1 updates
2016-11-01 17:22:16,621 client 6: gtk2.GLWindowBacking(3, (1587, 749), GBRP).gl_frame_terminator()
2016-11-01 17:22:16,631 client 6: Switching back to YUV paint state
2016-11-01 17:22:16,631 client 6: <OpenGL.platform.baseplatform.glBindFramebuffer object at 0xadf74f0>(GL_FRAMEBUFFER (36160), c_ulong(1L))
2016-11-01 17:22:16,632 packet decoding sequence 915 for window 3: 764x482 took 11.2ms
2016-11-01 17:22:16,632 record_latency: took   73.9 ms round trip,   73.8 for echo,   11.0 for decoding of   368248 pixels,     4168 bytes sent over the network in   62.7 ms,   62.6 ms for echo
2016-11-01 17:22:16,633 client 6: gtk2.GLWindowBacking(3, (1587, 749), GBRP).do_present_fbo() done
2016-11-01 17:22:16,633 client 6: record_decode_time(True, ) wid=3, h264: 764x482, 11.2ms
2016-11-01 17:22:16,633 client 6: after_draw_refresh(True, ) 764x482 at 146x150 encoding=h264, options={'speed': 63, 'csc': 'YUV444P', 'encoding': 'h264', 'type': 'P', 'frame': 31, 'quality': 50, 'pts': 1908}
2016-11-01 17:22:16,672 x264 encode YUV420P frame     0 as  IDR slice with 7 nals, tune=film, total    7021 bytes, keyframe=True , delayed=1
2016-11-01 17:22:16,674 compress:  21.1ms for  764x482  pixels at  146,150  for wid=3     using  h264 with ratio   0.5% ( 1441KB to     6KB), sequence   917, client_options={'pts': 0, 'frame': 0, 'delayed': 1, 'csc': 'YUV420P', 'paint': False, 'type': 'IDR', 'quality': 52, 'speed': 62}
2016-11-01 17:22:16,685 client 6: draw_region(146, 150, 764, 483, jpeg, 37034 bytes, 0, {'quality': 92}, [<function record_decode_time at 0x9f1ea70>, <function after_draw_refresh at 0x9f1e330>])
2016-11-01 17:22:16,690 client 6: gtk2.GLWindowBacking(3, (1587, 749), GBRP).do_paint_rgb(RGB, 1107036 bytes, x=146, y=150, width=764, height=483, rowstride=2292, options={'rgb_format': 'RGB', 'quality': 92, 'encoding': 'jpeg'})
2016-11-01 17:22:16,692 client 6: gtk2.GLWindowBacking(3, (1587, 749), GBRP).gl_context() GL Pixmap backing size: 1587 x 749, context=gtk2.GLContextManager(<gtk.DrawingArea object at 0xa84e328 (GtkDrawingArea at 0xc48bd8)>)
2016-11-01 17:22:16,692 client 6: Switching to RGB paint state
2016-11-01 17:22:16,693 client 6: RGB update at (146,150) size 764x483 (1107036 bytes), stride=2292, row length 0, alignment 4, using GL zerocopy:buffer-as-memoryview format=RGB
2016-11-01 17:22:16,693 client 6: present_fbo: adding (146, 150, 764, 483) to pending paint list (size=0), flush=0, paint_screen=True
2016-11-01 17:22:16,694 client 6: Presenting FBO on screen
2016-11-01 17:22:16,694 client 6: Switching to RGB paint state
2016-11-01 17:22:16,694 client 6: do_present_fbo: painting [(146, 150, 764, 483)]
2016-11-01 17:22:16,695 client 6: gtk2.GLWindowBacking(3, (1587, 749), GBRP).gl_show() flushing
2016-11-01 17:22:16,698 client 6: gl_show after  84ms took  0ms,  1 updates
2016-11-01 17:22:16,698 client 6: gtk2.GLWindowBacking(3, (1587, 749), GBRP).gl_frame_terminator()
2016-11-01 17:22:16,699 packet decoding sequence 916 for window 3: 764x483 took 11.9ms
2016-11-01 17:22:16,699 record_latency: took   79.1 ms round trip,   79.0 for echo,   11.0 for decoding of   369012 pixels,    37086 bytes sent over the network in   67.2 ms,   67.1 ms for echo
2016-11-01 17:22:16,700 client 6: Switching back to YUV paint state
2016-11-01 17:22:16,700 client 6: <OpenGL.platform.baseplatform.glBindFramebuffer object at 0xadf74f0>(GL_FRAMEBUFFER (36160), c_ulong(1L))
2016-11-01 17:22:16,703 client 6: gtk2.GLWindowBacking(3, (1587, 749), GBRP).do_present_fbo() done
2016-11-01 17:22:16,703 client 6: record_decode_time(True, ) wid=3, jpeg: 764x483, 11.8ms
2016-11-01 17:22:16,704 client 6: after_draw_refresh(True, ) 764x483 at 146x150 encoding=jpeg, options={'quality': 92, 'encoding': 'jpeg'}
2016-11-01 17:22:16,719 client 6: draw_region(146, 150, 764, 482, h264, 7021 bytes, 0, {'pts': 0, 'type': 'IDR', 'frame': 0, 'delayed': 1, 'csc': 'YUV420P', 'paint': False, 'quality': 52, 'speed': 62}, [<function record_decode_time at 0x11738770>, <function after_draw_refresh at 0x9f1ea70>])
2016-11-01 17:22:16,720 client 6: paint_with_video_decoder: colorspace changed from YUV444P to YUV420P
2016-11-01 17:22:16,722 client 6: paint_with_video_decoder: new <type 'xpra.codecs.dec_avcodec2.decoder.Decoder'>(764,482,YUV420P)
2016-11-01 17:22:16,723 client 6: paint_with_video_decoder: info={'decoder_height': 482, 'encoding': 'h264', 'colorspace': 'YUV420P', 'actual_colorspace': 'YUV420P', 'height': 482, 'decoder_width': 764, 'width': 764, 'version': (57, 48, 101), 'formats': ['YUV422P', 'BGRX', 'GBRP', 'RGB', 'YUV420P', 'BGRA', 'ARGB', 'XRGB', 'YUV444P'], 'frames': 0L, 'type': 'avcodec'}
2016-11-01 17:22:16,726 client 6: Error: avcodec error -35 decoding 7021 bytes of h264 data:
2016-11-01 17:22:16,726 client 6:  'Resource temporarily unavailable'
2016-11-01 17:22:16,726 client 6:  frame 0
2016-11-01 17:22:16,727 client 6:  options={'pts': 0, 'encoding': 'h264', 'type': 'IDR', 'frame': 0, 'delayed': 1, 'csc': 'YUV420P', 'paint': False, 'quality': 52, 'speed': 62}
2016-11-01 17:22:16,728 packet decoding sequence 917 for window 3: 764x482 took 9.1ms
2016-11-01 17:22:16,728 record_latency: took   54.0 ms round trip,   53.9 for echo,    9.0 for decoding of   368248 pixels,     7130 bytes sent over the network in   44.9 ms,   44.8 ms for echo
2016-11-01 17:22:16,728 client 6:  decoder state:
2016-11-01 17:22:16,729 client 6:   decoder_height = 482
2016-11-01 17:22:16,729 client 6:   encoding = h264
2016-11-01 17:22:16,732 client 6:   colorspace = YUV420P
2016-11-01 17:22:16,732 client 6:   actual_colorspace = YUV420P
2016-11-01 17:22:16,732 client 6:   height = 482
2016-11-01 17:22:16,733 client 6:   decoder_width = 764
2016-11-01 17:22:16,733 client 6:   width = 764
2016-11-01 17:22:16,733 client 6:   version = (57, 48, 101)
2016-11-01 17:22:16,733 client 6:   formats = ['YUV422P', 'BGRX', 'GBRP', 'RGB', 'YUV420P', 'BGRA', 'ARGB', 'XRGB', 'YUV444P']
2016-11-01 17:22:16,733 client 6:   frames = 0
2016-11-01 17:22:16,733 client 6:   type = avcodec
2016-11-01 17:22:16,734 client 6: record_decode_time(True, ) wid=3, h264: 764x482, 9.1ms
2016-11-01 17:22:16,734 client 6: after_draw_refresh(True, ) 764x482 at 146x150 encoding=h264, options={'pts': 0, 'encoding': 'h264', 'type': 'IDR', 'frame': 0, 'delayed': 1, 'csc': 'YUV420P', 'paint': False, 'quality': 52, 'speed': 62}
2016-11-01 17:22:16,735 x264 encode YUV420P frame     1 as    P slice with 4 nals, tune=film, total    1643 bytes, keyframe=False, delayed=1
2016-11-01 17:22:16,735 compress:  23.3ms for  764x482  pixels at  146,150  for wid=3     using  h264 with ratio   0.1% ( 1441KB to     1KB), sequence   918, client_options={'pts': 112, 'frame': 1, 'delayed': 1, 'csc': 'YUV420P', 'type': 'P', 'quality': 52, 'speed': 62}
2016-11-01 17:22:16,775 x264 encode YUV420P frame     2 as    B slice with 4 nals, tune=film, total     740 bytes, keyframe=False, delayed=1
2016-11-01 17:22:16,775 compress:  12.9ms for  764x482  pixels at  146,150  for wid=3     using  h264 with ratio   0.1% ( 1441KB to     0KB), sequence   919, client_options={'pts': 48, 'frame': 2, 'delayed': 1, 'csc': 'YUV420P', 'type': 'B', 'quality': 52, 'speed': 62}
2016-11-01 17:22:16,781 client 6: draw_region(146, 150, 764, 482, h264, 1643 bytes, 0, {'speed': 62, 'type': 'P', 'pts': 112, 'frame': 1, 'quality': 52, 'delayed': 1, 'csc': 'YUV420P'}, [<function record_decode_time at 0x11738770>, <function after_draw_refresh at 0x9f1ea70>])
2016-11-01 17:22:16,782 client 6: gl_paint_planar(0, 'h264', AVImageWrapper-None(YUV420P:(0, 0, 764, 482, 24):3_PLANES), 146, 150, 764, 482, 764, 482, [<function record_decode_time at 0x11738770>, <function after_draw_refresh at 0x9f1ea70>])
2016-11-01 17:22:16,783 client 6: gtk2.GLWindowBacking(3, (1587, 749), GBRP).gl_context() GL Pixmap backing size: 1587 x 749, context=gtk2.GLContextManager(<gtk.DrawingArea object at 0xa84e328 (GtkDrawingArea at 0xc48bd8)>)
2016-11-01 17:22:16,783 client 6: gtk2.GLWindowBacking(3, (1587, 749), GBRP).update_planar_textures(146, 150, 764, 482, AVImageWrapper-None(YUV420P:(0, 0, 764, 482, 24):3_PLANES), 'YUV420P')
2016-11-01 17:22:16,784 client 6: Creating new planar textures, pixel format YUV420P
2016-11-01 17:22:16,784 client 6: updating planar textures: 764x482 YUV420P
2016-11-01 17:22:16,785 client 6: texture 0: div=(1, 1), rowstride=768, 764x482, data=370176 bytes, upload=zerocopy:buffer-as-memoryview
2016-11-01 17:22:16,786 client 6: texture 1: div=(2, 2), rowstride=384, 382x241, data=92544 bytes, upload=zerocopy:buffer-as-memoryview
2016-11-01 17:22:16,787 client 6: texture 2: div=(2, 2), rowstride=384, 382x241, data=92544 bytes, upload=zerocopy:buffer-as-memoryview
2016-11-01 17:22:16,787 client 6: gtk2.GLWindowBacking(3, (1587, 749), YUV420P).render_planar_update(146, 150, 764, 482, 1, 1) pixel_format=YUV420P
2016-11-01 17:22:16,788 client 6: painting planar update, format YUV420P
2016-11-01 17:22:16,788 client 6: gtk2.GLWindowBacking(3, (1587, 749), YUV420P).render_planar_update(..) texture_size=(764, 482), size=(1587, 749)
2016-11-01 17:22:16,788 client 6: present_fbo: adding (146, 150, 764, 482) to pending paint list (size=0), flush=0, paint_screen=True
2016-11-01 17:22:16,790 client 6: Presenting FBO on screen
2016-11-01 17:22:16,790 client 6: Switching to RGB paint state
2016-11-01 17:22:16,790 client 6: do_present_fbo: painting [(146, 150, 764, 482)]
2016-11-01 17:22:16,791 client 6: gtk2.GLWindowBacking(3, (1587, 749), YUV420P).gl_show() flushing
2016-11-01 17:22:16,793 client 6: gl_show after  95ms took  1ms,  1 updates
2016-11-01 17:22:16,794 client 6: gtk2.GLWindowBacking(3, (1587, 749), YUV420P).gl_frame_terminator()
2016-11-01 17:22:16,795 client 6: Switching back to YUV paint state
2016-11-01 17:22:16,796 packet decoding sequence 918 for window 3: 764x482 took 13.3ms
2016-11-01 17:22:16,796 record_latency: took   59.8 ms round trip,   59.7 for echo,   13.0 for decoding of   368248 pixels,     1744 bytes sent over the network in   46.5 ms,   46.4 ms for echo
2016-11-01 17:22:16,796 client 6: <OpenGL.platform.baseplatform.glBindFramebuffer object at 0xadf74f0>(GL_FRAMEBUFFER (36160), c_ulong(1L))
2016-11-01 17:22:16,797 client 6: gtk2.GLWindowBacking(3, (1587, 749), YUV420P).do_present_fbo() done
2016-11-01 17:22:16,797 client 6: record_decode_time(True, ) wid=3, h264: 764x482, 13.3ms
2016-11-01 17:22:16,797 client 6: after_draw_refresh(True, ) 764x482 at 146x150 encoding=h264, options={'speed': 62, 'type': 'P', 'pts': 112, 'frame': 1, 'encoding': 'h264', 'quality': 52, 'delayed': 1, 'csc': 'YUV420P'}
2016-11-01 17:22:16,814 client 6: draw_region(146, 150, 764, 482, h264, 740 bytes, 0, {'speed': 62, 'type': 'B', 'pts': 48, 'frame': 2, 'quality': 52, 'delayed': 1, 'csc': 'YUV420P'}, [<function record_decode_time at 0x11738770>, <function after_draw_refresh at 0x9f1e330>])
2016-11-01 17:22:16,820 client 6: gl_paint_planar(0, 'h264', AVImageWrapper-None(YUV420P:(0, 0, 764, 482, 24):3_PLANES), 146, 150, 764, 482, 764, 482, [<function record_decode_time at 0x11738770>, <function after_draw_refresh at 0x9f1e330>])
2016-11-01 17:22:16,822 client 6: gtk2.GLWindowBacking(3, (1587, 749), YUV420P).gl_context() GL Pixmap backing size: 1587 x 749, context=gtk2.GLContextManager(<gtk.DrawingArea object at 0xa84e328 (GtkDrawingArea at 0xc48bd8)>)
2016-11-01 17:22:16,824 client 6: gtk2.GLWindowBacking(3, (1587, 749), YUV420P).update_planar_textures(146, 150, 764, 482, AVImageWrapper-None(YUV420P:(0, 0, 764, 482, 24):3_PLANES), 'YUV420P')
2016-11-01 17:22:16,825 client 6: updating planar textures: 764x482 YUV420P
2016-11-01 17:22:16,834 client 6: texture 0: div=(1, 1), rowstride=768, 764x482, data=370176 bytes, upload=zerocopy:buffer-as-memoryview
2016-11-01 17:22:16,834 packet decoding sequence 919 for window 3: 764x482 took 11.4ms
2016-11-01 17:22:16,835 record_latency: took   58.2 ms round trip,   58.0 for echo,   11.0 for decoding of   368248 pixels,      841 bytes sent over the network in   46.7 ms,   46.6 ms for echo
2016-11-01 17:22:16,835 client 6: texture 1: div=(2, 2), rowstride=384, 382x241, data=92544 bytes, upload=zerocopy:buffer-as-memoryview
2016-11-01 17:22:16,835 client 6: texture 2: div=(2, 2), rowstride=384, 382x241, data=92544 bytes, upload=zerocopy:buffer-as-memoryview
2016-11-01 17:22:16,835 client 6: gtk2.GLWindowBacking(3, (1587, 749), YUV420P).render_planar_update(146, 150, 764, 482, 1, 1) pixel_format=YUV420P
2016-11-01 17:22:16,835 client 6: painting planar update, format YUV420P
2016-11-01 17:22:16,835 client 6: gtk2.GLWindowBacking(3, (1587, 749), YUV420P).render_planar_update(..) texture_size=(764, 482), size=(1587, 749)
2016-11-01 17:22:16,835 client 6: present_fbo: adding (146, 150, 764, 482) to pending paint list (size=0), flush=0, paint_screen=True
2016-11-01 17:22:16,835 client 6: Presenting FBO on screen
2016-11-01 17:22:16,836 client 6: Switching to RGB paint state
2016-11-01 17:22:16,836 client 6: do_present_fbo: painting [(146, 150, 764, 482)]
2016-11-01 17:22:16,836 client 6: gtk2.GLWindowBacking(3, (1587, 749), YUV420P).gl_show() flushing
2016-11-01 17:22:16,836 client 6: gl_show after  30ms took  1ms,  1 updates
2016-11-01 17:22:16,836 client 6: gtk2.GLWindowBacking(3, (1587, 749), YUV420P).gl_frame_terminator()
2016-11-01 17:22:16,836 client 6: Switching back to YUV paint state
2016-11-01 17:22:16,836 client 6: <OpenGL.platform.baseplatform.glBindFramebuffer object at 0xadf74f0>(GL_FRAMEBUFFER (36160), c_ulong(1L))
2016-11-01 17:22:16,837 client 6: gtk2.GLWindowBacking(3, (1587, 749), YUV420P).do_present_fbo() done
2016-11-01 17:22:16,837 client 6: record_decode_time(True, ) wid=3, h264: 764x482, 11.4ms
2016-11-01 17:22:16,837 client 6: after_draw_refresh(True, ) 764x482 at 146x150 encoding=h264, options={'speed': 62, 'type': 'B', 'pts': 48, 'frame': 2, 'encoding': 'h264', 'quality': 52, 'delayed': 1, 'csc': 'YUV420P'}
2016-11-01 17:22:16,840 x264 encode YUV420P frame     3 as    P slice with 4 nals, tune=film, total    1842 bytes, keyframe=False, delayed=1
2016-11-01 17:22:16,844 compress:  25.4ms for  764x482  pixels at  146,150  for wid=3     using  h264 with ratio   0.1% ( 1441KB to     1KB), sequence   920, client_options={'pts': 212, 'frame': 3, 'delayed': 1, 'csc': 'YUV420P', 'type': 'P', 'quality': 52, 'speed': 62}
2016-11-01 17:22:16,855 x264 encode YUV420P frame     4 as    B slice with 4 nals, tune=film, total     739 bytes, keyframe=False, delayed=1
2016-11-01 17:22:16,855 compress:  10.8ms for  764x482  pixels at  146,150  for wid=3     using  h264 with ratio   0.1% ( 1441KB to     0KB), sequence   921, client_options={'pts': 157, 'frame': 4, 'delayed': 1, 'csc': 'YUV420P', 'type': 'B', 'quality': 52, 'speed': 62}
2016-11-01 17:22:16,886 client 6: draw_region(146, 150, 764, 482, h264, 1842 bytes, 0, {'speed': 62, 'type': 'P', 'pts': 212, 'frame': 3, 'quality': 52, 'delayed': 1, 'csc': 'YUV420P'}, [<function record_decode_time at 0x11738770>, <function after_draw_refresh at 0x9f1e970>])
2016-11-01 17:22:16,887 client 6: gl_paint_planar(0, 'h264', AVImageWrapper-None(YUV420P:(0, 0, 764, 482, 24):3_PLANES), 146, 150, 764, 482, 764, 482, [<function record_decode_time at 0x11738770>, <function after_draw_refresh at 0x9f1e970>])
2016-11-01 17:22:16,888 client 6: gtk2.GLWindowBacking(3, (1587, 749), YUV420P).gl_context() GL Pixmap backing size: 1587 x 749, context=gtk2.GLContextManager(<gtk.DrawingArea object at 0xa84e328 (GtkDrawingArea at 0xc48bd8)>)
2016-11-01 17:22:16,889 client 6: gtk2.GLWindowBacking(3, (1587, 749), YUV420P).update_planar_textures(146, 150, 764, 482, AVImageWrapper-None(YUV420P:(0, 0, 764, 482, 24):3_PLANES), 'YUV420P')
2016-11-01 17:22:16,890 client 6: updating planar textures: 764x482 YUV420P
2016-11-01 17:22:16,890 client 6: texture 0: div=(1, 1), rowstride=768, 764x482, data=370176 bytes, upload=zerocopy:buffer-as-memoryview
2016-11-01 17:22:16,891 client 6: texture 1: div=(2, 2), rowstride=384, 382x241, data=92544 bytes, upload=zerocopy:buffer-as-memoryview
2016-11-01 17:22:16,891 client 6: texture 2: div=(2, 2), rowstride=384, 382x241, data=92544 bytes, upload=zerocopy:buffer-as-memoryview
2016-11-01 17:22:16,891 client 6: gtk2.GLWindowBacking(3, (1587, 749), YUV420P).render_planar_update(146, 150, 764, 482, 1, 1) pixel_format=YUV420P
2016-11-01 17:22:16,892 client 6: painting planar update, format YUV420P
2016-11-01 17:22:16,893 client 6: gtk2.GLWindowBacking(3, (1587, 749), YUV420P).render_planar_update(..) texture_size=(764, 482), size=(1587, 749)
2016-11-01 17:22:16,893 client 6: present_fbo: adding (146, 150, 764, 482) to pending paint list (size=0), flush=0, paint_screen=True
2016-11-01 17:22:16,893 client 6: Presenting FBO on screen
2016-11-01 17:22:16,894 client 6: Switching to RGB paint state
2016-11-01 17:22:16,895 client 6: do_present_fbo: painting [(146, 150, 764, 482)]
2016-11-01 17:22:16,896 client 6: gtk2.GLWindowBacking(3, (1587, 749), YUV420P).gl_show() flushing
2016-11-01 17:22:16,898 client 6: gl_show after  77ms took  3ms,  1 updates
2016-11-01 17:22:16,902 client 6: gtk2.GLWindowBacking(3, (1587, 749), YUV420P).gl_frame_terminator()
2016-11-01 17:22:16,902 client 6: Switching back to YUV paint state
2016-11-01 17:22:16,903 client 6: <OpenGL.platform.baseplatform.glBindFramebuffer object at 0xadf74f0>(GL_FRAMEBUFFER (36160), c_ulong(1L))
2016-11-01 17:22:16,903 packet decoding sequence 920 for window 3: 764x482 took 17.0ms
2016-11-01 17:22:16,903 record_latency: took   57.7 ms round trip,   57.7 for echo,   17.0 for decoding of   368248 pixels,     1944 bytes sent over the network in   40.7 ms,   40.6 ms for echo
2016-11-01 17:22:16,907 client 6: gtk2.GLWindowBacking(3, (1587, 749), YUV420P).do_present_fbo() done
2016-11-01 17:22:16,907 client 6: record_decode_time(True, ) wid=3, h264: 764x482, 17.0ms
2016-11-01 17:22:16,907 client 6: after_draw_refresh(True, ) 764x482 at 146x150 encoding=h264, options={'speed': 62, 'type': 'P', 'pts': 212, 'frame': 3, 'encoding': 'h264', 'quality': 52, 'delayed': 1, 'csc': 'YUV420P'}
2016-11-01 17:22:16,908 client 6: draw_region(146, 150, 764, 482, h264, 739 bytes, 0, {'speed': 62, 'type': 'B', 'pts': 157, 'frame': 4, 'quality': 52, 'delayed': 1, 'csc': 'YUV420P'}, [<function record_decode_time at 0x11738770>, <function after_draw_refresh at 0x9f1e970>])
2016-11-01 17:22:16,909 client 6: gl_paint_planar(0, 'h264', AVImageWrapper-None(YUV420P:(0, 0, 764, 482, 24):3_PLANES), 146, 150, 764, 482, 764, 482, [<function record_decode_time at 0x11738770>, <function after_draw_refresh at 0x9f1e970>])
2016-11-01 17:22:16,910 client 6: gtk2.GLWindowBacking(3, (1587, 749), YUV420P).gl_context() GL Pixmap backing size: 1587 x 749, context=gtk2.GLContextManager(<gtk.DrawingArea object at 0xa84e328 (GtkDrawingArea at 0xc48bd8)>)
2016-11-01 17:22:16,912 client 6: gtk2.GLWindowBacking(3, (1587, 749), YUV420P).update_planar_textures(146, 150, 764, 482, AVImageWrapper-None(YUV420P:(0, 0, 764, 482, 24):3_PLANES), 'YUV420P')
2016-11-01 17:22:16,913 client 6: updating planar textures: 764x482 YUV420P
2016-11-01 17:22:16,913 client 6: texture 0: div=(1, 1), rowstride=768, 764x482, data=370176 bytes, upload=zerocopy:buffer-as-memoryview
2016-11-01 17:22:16,913 client 6: texture 1: div=(2, 2), rowstride=384, 382x241, data=92544 bytes, upload=zerocopy:buffer-as-memoryview
2016-11-01 17:22:16,913 client 6: texture 2: div=(2, 2), rowstride=384, 382x241, data=92544 bytes, upload=zerocopy:buffer-as-memoryview
2016-11-01 17:22:16,914 client 6: gtk2.GLWindowBacking(3, (1587, 749), YUV420P).render_planar_update(146, 150, 764, 482, 1, 1) pixel_format=YUV420P
2016-11-01 17:22:16,914 client 6: painting planar update, format YUV420P
2016-11-01 17:22:16,914 client 6: gtk2.GLWindowBacking(3, (1587, 749), YUV420P).render_planar_update(..) texture_size=(764, 482), size=(1587, 749)
2016-11-01 17:22:16,914 client 6: present_fbo: adding (146, 150, 764, 482) to pending paint list (size=0), flush=0, paint_screen=True
2016-11-01 17:22:16,914 client 6: Presenting FBO on screen
2016-11-01 17:22:16,915 client 6: Switching to RGB paint state
2016-11-01 17:22:16,915 client 6: do_present_fbo: painting [(146, 150, 764, 482)]
2016-11-01 17:22:16,915 client 6: gtk2.GLWindowBacking(3, (1587, 749), YUV420P).gl_show() flushing
2016-11-01 17:22:16,916 client 6: gl_show after  16ms took  1ms,  1 updates
2016-11-01 17:22:16,916 client 6: gtk2.GLWindowBacking(3, (1587, 749), YUV420P).gl_frame_terminator()
2016-11-01 17:22:16,918 packet decoding sequence 921 for window 3: 764x482 took 13.6ms
2016-11-01 17:22:16,918 record_latency: took   62.2 ms round trip,   62.2 for echo,   13.0 for decoding of   368248 pixels,      841 bytes sent over the network in   48.6 ms,   48.5 ms for echo
2016-11-01 17:22:16,918 client 6: Switching back to YUV paint state
2016-11-01 17:22:16,919 client 6: <OpenGL.platform.baseplatform.glBindFramebuffer object at 0xadf74f0>(GL_FRAMEBUFFER (36160), c_ulong(1L))
2016-11-01 17:22:16,919 client 6: gtk2.GLWindowBacking(3, (1587, 749), YUV420P).do_present_fbo() done
2016-11-01 17:22:16,920 client 6: record_decode_time(True, ) wid=3, h264: 764x482, 13.6ms
2016-11-01 17:22:16,921 client 6: after_draw_refresh(True, ) 764x482 at 146x150 encoding=h264, options={'speed': 62, 'type': 'B', 'pts': 157, 'frame': 4, 'encoding': 'h264', 'quality': 52, 'delayed': 1, 'csc': 'YUV420P'}

totaam · 2016-11-02T00:52:05Z

2016-11-02 00:52:05: afarr commented

Ohh... and as for the errors I was seeing with XPRA_X264_THREADS=1 and XPRA_X264_SLICED_THREADS=0... I've figured out why you're not seeing them.

Somehow, rather than XPRA_X264_THREADS=1, I managed to try to test using XPRA_CPU_THREADS=1 - which I'm not even sure is a real property, but using it seems to trigger a lot of errors.

While figuring out where I'd gone wrong (I've no idea still quite how), I did notice that testing with the correct variables (XPRA_X264_THREADS=1 and XPRA_X264_SLICED_THREADS=0), I am in fact not able to repro... as you'd expected previously. (At least that's one mystery solved, and a far less nerve wracking mystery substituted in its place.)

totaam · 2016-11-02T04:06:23Z

2016-11-02 04:06:23: antoine changed owner from antoine to afarr

totaam · 2016-11-02T04:06:23Z

2016-11-02 04:06:23: antoine commented

Replying to comment:7 : do we need to change the defaults settings for x264 threads?
Do you get errors with the default settings but not if you disable sliced threads? (do you need both environment variables to get rid of the problem?)
Note: this code has been present for a very long time, maybe the error is only triggering now because of b-frames.

Can you reproduce the error from comment:6 with a more up to date server?
If so, does it go away (or become harder to hit?) if you turn off b-frames on the server?

There were some important fixes in this area recently:

r14367 better debug logging

r14365 huge libyuv bug
You already had:

r14301 safer video pipeline code

r14300 race condition

r14299 + r14298 fix for b-frames flushing with video scaling enabled

totaam · 2016-11-04T01:55:49Z

2016-11-04 01:55:49: afarr changed owner from afarr to antoine

totaam · 2016-11-04T01:55:49Z

2016-11-04 01:55:49: afarr commented

... I am able to still reproduce the error from comment:6 ... using fedora 23 server 1.0 r14390 (just built it, as up to date as I know how to get)... though I'm still using a 1.0 r14155 osx client (shouldn't be an issue, but just sayin').

With the same -d stat,x264,compress flags, server side:

2016-11-03 18:08:04,309 x264 close context 0x0
2016-11-03 18:08:04,317 x264 context=0x7f46a11e3160, YUV420P  854x480  quality=62, speed=96, source=video
2016-11-03 18:08:04,317  preset=superfast, profile=high10, tune=film
2016-11-03 18:08:04,317  me=DIA, me_range=16, mv_range=-1, b-frames=1, max delayed frames=1
2016-11-03 18:08:04,318  vfr-input=0, lookahead=0, sync-lookahead=-1, mb-tree=0, bframe-adaptive=FAST
2016-11-03 18:08:04,319  threads=auto, sliced-threads=True
2016-11-03 18:08:04,326 x264 encode 1 delayed frames after 0
2016-11-03 18:08:04,334 compress:  24.4ms for  854x480  pixels at  146,150  for wid=2     using  jpeg with ratio   4.3% ( 1601KB to    69KB), sequence  8546, client_options={'quality': 99}
2016-11-03 18:08:04,344 client 1: draw_region(146, 150, 854, 480, jpeg, 70809 bytes, 0, {'quality': 99}, [<function record_decode_time at 0x69097f0>, <function after_draw_refresh at 0x6b87fb0>])
2016-11-03 18:08:04,355 client 1: gtk2.GLWindowBacking(2, (1587, 749), GBRP).do_paint_rgb(RGB, 1229760 bytes, x=146, y=150, width=854, height=480, rowstride=2562, options={'rgb_format': 'RGB', 'quality': 99, 'encoding': 'jpeg'})
2016-11-03 18:08:04,355 client 1: gtk2.GLWindowBacking(2, (1587, 749), GBRP).gl_context() GL Pixmap backing size: 1587 x 749, context=gtk2.GLContextManager(<gtk.DrawingArea object at 0x87776e8 (GtkDrawingArea at 0x2ad6b58)>)
2016-11-03 18:08:04,357 client 1: Switching to RGB paint state
2016-11-03 18:08:04,357 client 1: RGB update at (146,150) size 854x480 (1229760 bytes), stride=2562, row length 0, alignment 2, using GL zerocopy:buffer-as-memoryview format=RGB
2016-11-03 18:08:04,357 client 1: present_fbo: adding (146, 150, 854, 480) to pending paint list (size=0), flush=0, paint_screen=True
2016-11-03 18:08:04,357 client 1: Presenting FBO on screen
2016-11-03 18:08:04,359 client 1: Switching to RGB paint state
2016-11-03 18:08:04,359 client 1: do_present_fbo: painting [(146, 150, 854, 480)]
2016-11-03 18:08:04,359 client 1: gtk2.GLWindowBacking(2, (1587, 749), GBRP).gl_show() flushing
2016-11-03 18:08:04,360 client 1: gl_show after  85ms took  3ms,  1 updates
2016-11-03 18:08:04,360 client 1: gtk2.GLWindowBacking(2, (1587, 749), GBRP).gl_frame_terminator()
2016-11-03 18:08:04,360 client 1: Switching back to YUV paint state
2016-11-03 18:08:04,360 client 1: <OpenGL.platform.baseplatform.glBindFramebuffer object at 0xbd1d4f0>(GL_FRAMEBUFFER (36160), c_ulong(2L))
2016-11-03 18:08:04,360 client 1: gtk2.GLWindowBacking(2, (1587, 749), GBRP).do_present_fbo() done
2016-11-03 18:08:04,362 client 1: record_decode_time(True, ) wid=2, jpeg: 854x480, 16.6ms
2016-11-03 18:08:04,363 client 1: after_draw_refresh(True, ) 854x480 at 146x150 encoding=jpeg, options={'quality': 99, 'encoding': 'jpeg'}
2016-11-03 18:08:04,366 x264 encode YUV420P frame     0 as  IDR slice with 7 nals, tune=film, total   23122 bytes, keyframe=True , delayed=1
2016-11-03 18:08:04,366 compress:  12.9ms for  854x480  pixels at  146,150  for wid=2     using  h264 with ratio   1.4% ( 1601KB to    22KB), sequence  8547, client_options={'pts': 0, 'frame': 0, 'delayed': 1, 'csc': 'YUV420P', 'paint': False, 'type': 'IDR', 'quality': 62, 'speed': 96}
2016-11-03 18:08:04,372 client 1: draw_region(146, 150, 854, 480, h264, 23122 bytes, 0, {'pts': 0, 'type': 'IDR', 'frame': 0, 'delayed': 1, 'csc': 'YUV420P', 'paint': False, 'quality': 62, 'speed': 96}, [<function record_decode_time at 0x69097f0>, <function after_draw_refresh at 0x6b87fb0>])
2016-11-03 18:08:04,374 client 1: paint_with_video_decoder: colorspace changed from YUV444P to YUV420P
2016-11-03 18:08:04,374 client 1: paint_with_video_decoder: new <type 'xpra.codecs.dec_avcodec2.decoder.Decoder'>(854,480,YUV420P)
2016-11-03 18:08:04,374 client 1: paint_with_video_decoder: info={'decoder_height': 480, 'encoding': 'h264', 'colorspace': 'YUV420P', 'actual_colorspace': 'YUV420P', 'height': 480, 'decoder_width': 854, 'width': 854, 'version': (57, 48, 101), 'formats': ['YUV422P', 'BGRX', 'GBRP', 'RGB', 'YUV420P', 'BGRA', 'ARGB', 'XRGB', 'YUV444P'], 'frames': 0L, 'type': 'avcodec'}
2016-11-03 18:08:04,378 client 1: Error: avcodec error -35 decoding 23122 bytes of h264 data:
2016-11-03 18:08:04,378 client 1:  'Resource temporarily unavailable'
2016-11-03 18:08:04,380 client 1:  frame 0
2016-11-03 18:08:04,380 client 1:  options={'pts': 0, 'encoding': 'h264', 'type': 'IDR', 'frame': 0, 'delayed': 1, 'csc': 'YUV420P', 'paint': False, 'quality': 62, 'speed': 96}
2016-11-03 18:08:04,381 client 1:  decoder state:
2016-11-03 18:08:04,381 client 1:   decoder_height = 480
2016-11-03 18:08:04,382 client 1:   encoding = h264
2016-11-03 18:08:04,382 client 1:   colorspace = YUV420P
2016-11-03 18:08:04,382 client 1:   actual_colorspace = YUV420P
2016-11-03 18:08:04,383 client 1:   height = 480
2016-11-03 18:08:04,383 client 1:   decoder_width = 854
2016-11-03 18:08:04,384 client 1:   width = 854
2016-11-03 18:08:04,385 client 1:   version = (57, 48, 101)
2016-11-03 18:08:04,385 client 1:   formats = ['YUV422P', 'BGRX', 'GBRP', 'RGB', 'YUV420P', 'BGRA', 'ARGB', 'XRGB', 'YUV444P']
2016-11-03 18:08:04,386 client 1:   frames = 0
2016-11-03 18:08:04,386 client 1:   type = avcodec
2016-11-03 18:08:04,386 client 1: record_decode_time(True, ) wid=2, h264: 854x480, 12.3ms
2016-11-03 18:08:04,386 client 1: after_draw_refresh(True, ) 854x480 at 146x150 encoding=h264, options={'pts': 0, 'encoding': 'h264', 'type': 'IDR', 'frame': 0, 'delayed': 1, 'csc': 'YUV420P', 'paint': False, 'quality': 62, 'speed': 96}
2016-11-03 18:08:04,449 x264 encode YUV420P frame     1 as    P slice with 4 nals, tune=film, total    7900 bytes, keyframe=False, delayed=1
2016-11-03 18:08:04,450 compress:  12.5ms for  854x480  pixels at  146,150  for wid=2     using  h264 with ratio   0.5% ( 1601KB to     7KB), sequence  8548, client_options={'pts': 117, 'frame': 1, 'delayed': 1, 'csc': 'YUV420P', 'type': 'P', 'quality': 62, 'speed': 96}
2016-11-03 18:08:04,453 client 1: draw_region(146, 150, 854, 480, h264, 7900 bytes, 0, {'speed': 96, 'type': 'P', 'pts': 117, 'frame': 1, 'quality': 62, 'delayed': 1, 'csc': 'YUV420P'}, [<function record_decode_time at 0x69097f0>, <function after_draw_refresh at 0x6b87fb0>])
2016-11-03 18:08:04,456 client 1: gl_paint_planar(0, 'h264', AVImageWrapper-None(YUV420P:(0, 0, 854, 480, 24):3_PLANES), 146, 150, 854, 480, 854, 480, [<function record_decode_time at 0x69097f0>, <function after_draw_refresh at 0x6b87fb0>])
2016-11-03 18:08:04,457 client 1: gtk2.GLWindowBacking(2, (1587, 749), GBRP).gl_context() GL Pixmap backing size: 1587 x 749, context=gtk2.GLContextManager(<gtk.DrawingArea object at 0x87776e8 (GtkDrawingArea at 0x2ad6b58)>)
2016-11-03 18:08:04,458 client 1: gtk2.GLWindowBacking(2, (1587, 749), GBRP).update_planar_textures(146, 150, 854, 480, AVImageWrapper-None(YUV420P:(0, 0, 854, 480, 24):3_PLANES), 'YUV420P')
2016-11-03 18:08:04,458 client 1: Creating new planar textures, pixel format YUV420P
2016-11-03 18:08:04,458 client 1: updating planar textures: 854x480 YUV420P
2016-11-03 18:08:04,459 client 1: texture 0: div=(1, 1), rowstride=896, 854x480, data=430080 bytes, upload=zerocopy:buffer-as-memoryview
2016-11-03 18:08:04,459 client 1: texture 1: div=(2, 2), rowstride=448, 427x240, data=107520 bytes, upload=zerocopy:buffer-as-memoryview
2016-11-03 18:08:04,460 client 1: texture 2: div=(2, 2), rowstride=448, 427x240, data=107520 bytes, upload=zerocopy:buffer-as-memoryview
2016-11-03 18:08:04,461 client 1: gtk2.GLWindowBacking(2, (1587, 749), YUV420P).render_planar_update(146, 150, 854, 480, 1, 1) pixel_format=YUV420P
2016-11-03 18:08:04,461 client 1: painting planar update, format YUV420P
2016-11-03 18:08:04,462 client 1: gtk2.GLWindowBacking(2, (1587, 749), YUV420P).render_planar_update(..) texture_size=(854, 480), size=(1587, 749)
2016-11-03 18:08:04,462 client 1: present_fbo: adding (146, 150, 854, 480) to pending paint list (size=0), flush=0, paint_screen=True
2016-11-03 18:08:04,463 client 1: Presenting FBO on screen
2016-11-03 18:08:04,463 client 1: Switching to RGB paint state
2016-11-03 18:08:04,463 client 1: do_present_fbo: painting [(146, 150, 854, 480)]
2016-11-03 18:08:04,463 client 1: gtk2.GLWindowBacking(2, (1587, 749), YUV420P).gl_show() flushing
2016-11-03 18:08:04,466 client 1: gl_show after 108ms took  4ms,  1 updates
2016-11-03 18:08:04,469 client 1: gtk2.GLWindowBacking(2, (1587, 749), YUV420P).gl_frame_terminator()
2016-11-03 18:08:04,470 client 1: Switching back to YUV paint state
2016-11-03 18:08:04,471 client 1: <OpenGL.platform.baseplatform.glBindFramebuffer object at 0xbd1d4f0>(GL_FRAMEBUFFER (36160), c_ulong(2L))
2016-11-03 18:08:04,471 client 1: gtk2.GLWindowBacking(2, (1587, 749), YUV420P).do_present_fbo() done
2016-11-03 18:08:04,471 client 1: record_decode_time(True, ) wid=2, h264: 854x480, 13.7ms
2016-11-03 18:08:04,471 client 1: after_draw_refresh(True, ) 854x480 at 146x150 encoding=h264, options={'speed': 96, 'type': 'P', 'pts': 117, 'frame': 1, 'encoding': 'h264', 'quality': 62, 'delayed': 1, 'csc': 'YUV420P'}
2016-11-03 18:08:04,511 x264 encode YUV420P frame     2 as    B slice with 4 nals, tune=film, total    1857 bytes, keyframe=False, delayed=1
2016-11-03 18:08:04,511 compress:   8.5ms for  854x480  pixels at  146,150  for wid=2     using  h264 with ratio   0.1% ( 1601KB to     1KB), sequence  8549, client_options={'pts': 36, 'frame': 2, 'delayed': 1, 'csc': 'YUV420P', 'type': 'B', 'quality': 62, 'speed': 96}
2016-11-03 18:08:04,515 client 1: draw_region(146, 150, 854, 480, h264, 1857 bytes, 0, {'speed': 96, 'type': 'B', 'pts': 36, 'frame': 2, 'quality': 62, 'delayed': 1, 'csc': 'YUV420P'}, [<function record_decode_time at 0x69097f0>, <function after_draw_refresh at 0x6b87fb0>])
2016-11-03 18:08:04,520 client 1: gl_paint_planar(0, 'h264', AVImageWrapper-None(YUV420P:(0, 0, 854, 480, 24):3_PLANES), 146, 150, 854, 480, 854, 480, [<function record_decode_time at 0x69097f0>, <function after_draw_refresh at 0x6b87fb0>])
2016-11-03 18:08:04,521 client 1: gtk2.GLWindowBacking(2, (1587, 749), YUV420P).gl_context() GL Pixmap backing size: 1587 x 749, context=gtk2.GLContextManager(<gtk.DrawingArea object at 0x87776e8 (GtkDrawingArea at 0x2ad6b58)>)
2016-11-03 18:08:04,522 client 1: gtk2.GLWindowBacking(2, (1587, 749), YUV420P).update_planar_textures(146, 150, 854, 480, AVImageWrapper-None(YUV420P:(0, 0, 854, 480, 24):3_PLANES), 'YUV420P')
2016-11-03 18:08:04,522 client 1: updating planar textures: 854x480 YUV420P
2016-11-03 18:08:04,523 client 1: texture 0: div=(1, 1), rowstride=896, 854x480, data=430080 bytes, upload=zerocopy:buffer-as-memoryview
2016-11-03 18:08:04,523 client 1: texture 1: div=(2, 2), rowstride=448, 427x240, data=107520 bytes, upload=zerocopy:buffer-as-memoryview
2016-11-03 18:08:04,523 client 1: texture 2: div=(2, 2), rowstride=448, 427x240, data=107520 bytes, upload=zerocopy:buffer-as-memoryview
2016-11-03 18:08:04,524 client 1: gtk2.GLWindowBacking(2, (1587, 749), YUV420P).render_planar_update(146, 150, 854, 480, 1, 1) pixel_format=YUV420P
2016-11-03 18:08:04,527 client 1: painting planar update, format YUV420P
2016-11-03 18:08:04,527 client 1: gtk2.GLWindowBacking(2, (1587, 749), YUV420P).render_planar_update(..) texture_size=(854, 480), size=(1587, 749)
2016-11-03 18:08:04,528 client 1: present_fbo: adding (146, 150, 854, 480) to pending paint list (size=0), flush=0, paint_screen=True
2016-11-03 18:08:04,528 client 1: Presenting FBO on screen
2016-11-03 18:08:04,530 client 1: Switching to RGB paint state
2016-11-03 18:08:04,530 client 1: do_present_fbo: painting [(146, 150, 854, 480)]
2016-11-03 18:08:04,530 client 1: gtk2.GLWindowBacking(2, (1587, 749), YUV420P).gl_show() flushing
2016-11-03 18:08:04,530 client 1: gl_show after  60ms took  0ms,  1 updates
2016-11-03 18:08:04,530 client 1: gtk2.GLWindowBacking(2, (1587, 749), YUV420P).gl_frame_terminator()
2016-11-03 18:08:04,531 client 1: Switching back to YUV paint state
2016-11-03 18:08:04,531 client 1: <OpenGL.platform.baseplatform.glBindFramebuffer object at 0xbd1d4f0>(GL_FRAMEBUFFER (36160), c_ulong(2L))
2016-11-03 18:08:04,531 client 1: gtk2.GLWindowBacking(2, (1587, 749), YUV420P).do_present_fbo() done
2016-11-03 18:08:04,531 client 1: record_decode_time(True, ) wid=2, h264: 854x480, 12.1ms
2016-11-03 18:08:04,531 client 1: after_draw_refresh(True, ) 854x480 at 146x150 encoding=h264, options={'speed': 96, 'type': 'B', 'pts': 36, 'frame': 2, 'encoding': 'h264', 'quality': 62, 'delayed': 1, 'csc': 'YUV420P'}

Tried launching with XPRA_B_FRAMES=0 ... and was indeed able to produce the message again (not much more difficult to trigger... though neither is simple to trigger... require nearly a minute of dedicated patience).

2016-11-03 18:21:20,475 x264 close context 0x0
2016-11-03 18:21:20,483 x264 context=0x7f8788733640, YUV420P  854x480  quality=58, speed=95, source=video
2016-11-03 18:21:20,483  preset=superfast, profile=high10, tune=film
2016-11-03 18:21:20,483  me=DIA, me_range=16, mv_range=-1, b-frames=1, max delayed frames=1
2016-11-03 18:21:20,484  vfr-input=0, lookahead=0, sync-lookahead=-1, mb-tree=0, bframe-adaptive=FAST
2016-11-03 18:21:20,484  threads=auto, sliced-threads=True
2016-11-03 18:21:20,492 x264 encode 1 delayed frames after 0
2016-11-03 18:21:20,502 compress:  26.2ms for  854x480  pixels at  147,150  for wid=2     using  jpeg with ratio   4.8% ( 1601KB to    76KB), sequence  1771, client_options={'quality': 98}
2016-11-03 18:21:20,514 client 1: draw_region(147, 150, 854, 480, jpeg, 78036 bytes, 0, {'quality': 98}, [<function record_decode_time at 0x10861ab0>, <function after_draw_refresh at 0x10861cb0>])
2016-11-03 18:21:20,521 client 1: gtk2.GLWindowBacking(2, (1589, 1026), GBRP).do_paint_rgb(RGB, 1229760 bytes, x=147, y=150, width=854, height=480, rowstride=2562, options={'rgb_format': 'RGB', 'quality': 98, 'encoding': 'jpeg'})
2016-11-03 18:21:20,521 client 1: gtk2.GLWindowBacking(2, (1589, 1026), GBRP).gl_context() GL Pixmap backing size: 1589 x 1026, context=gtk2.GLContextManager(<gtk.DrawingArea object at 0xb85d418 (GtkDrawingArea at 0x49ffb58)>)
2016-11-03 18:21:20,522 client 1: Switching to RGB paint state
2016-11-03 18:21:20,523 client 1: RGB update at (147,150) size 854x480 (1229760 bytes), stride=2562, row length 0, alignment 2, using GL zerocopy:buffer-as-memoryview format=RGB
2016-11-03 18:21:20,526 client 1: present_fbo: adding (147, 150, 854, 480) to pending paint list (size=0), flush=0, paint_screen=True
2016-11-03 18:21:20,527 client 1: Presenting FBO on screen
2016-11-03 18:21:20,527 client 1: Switching to RGB paint state
2016-11-03 18:21:20,527 client 1: do_present_fbo: painting [(147, 150, 854, 480)]
2016-11-03 18:21:20,528 client 1: gtk2.GLWindowBacking(2, (1589, 1026), GBRP).gl_show() flushing
2016-11-03 18:21:20,529 client 1: gl_show after  81ms took  4ms,  1 updates
2016-11-03 18:21:20,532 client 1: gtk2.GLWindowBacking(2, (1589, 1026), GBRP).gl_frame_terminator()
2016-11-03 18:21:20,532 client 1: Switching back to YUV paint state
2016-11-03 18:21:20,532 client 1: <OpenGL.platform.baseplatform.glBindFramebuffer object at 0xbf374f0>(GL_FRAMEBUFFER (36160), c_ulong(1L))
2016-11-03 18:21:20,533 client 1: gtk2.GLWindowBacking(2, (1589, 1026), GBRP).do_present_fbo() done
2016-11-03 18:21:20,533 client 1: record_decode_time(True, ) wid=2, jpeg: 854x480, 15.2ms
2016-11-03 18:21:20,533 client 1: after_draw_refresh(True, ) 854x480 at 147x150 encoding=jpeg, options={'quality': 98, 'encoding': 'jpeg'}
2016-11-03 18:21:20,543 x264 encode YUV420P frame     0 as  IDR slice with 7 nals, tune=film, total   23145 bytes, keyframe=True , delayed=1
2016-11-03 18:21:20,543 compress:  16.8ms for  854x480  pixels at  147,150  for wid=2     using  h264 with ratio   1.4% ( 1601KB to    22KB), sequence  1772, client_options={'pts': 0, 'frame': 0, 'delayed': 1, 'csc': 'YUV420P', 'paint': False, 'type': 'IDR', 'quality': 58, 'speed': 95}
2016-11-03 18:21:20,554 client 1: draw_region(147, 150, 854, 480, h264, 23145 bytes, 0, {'pts': 0, 'type': 'IDR', 'frame': 0, 'delayed': 1, 'csc': 'YUV420P', 'paint': False, 'quality': 58, 'speed': 95}, [<function record_decode_time at 0x10861df0>, <function after_draw_refresh at 0x10861870>])
2016-11-03 18:21:20,555 client 1: paint_with_video_decoder: colorspace changed from YUV444P to YUV420P
2016-11-03 18:21:20,555 client 1: paint_with_video_decoder: new <type 'xpra.codecs.dec_avcodec2.decoder.Decoder'>(854,480,YUV420P)
2016-11-03 18:21:20,555 client 1: paint_with_video_decoder: info={'decoder_height': 480, 'encoding': 'h264', 'colorspace': 'YUV420P', 'actual_colorspace': 'YUV420P', 'height': 480, 'decoder_width': 854, 'width': 854, 'version': (57, 48, 101), 'formats': ['YUV422P', 'BGRX', 'GBRP', 'RGB', 'YUV420P', 'BGRA', 'ARGB', 'XRGB', 'YUV444P'], 'frames': 0L, 'type': 'avcodec'}
2016-11-03 18:21:20,557 client 1: Error: avcodec error -35 decoding 23145 bytes of h264 data:
2016-11-03 18:21:20,558 client 1:  'Resource temporarily unavailable'
2016-11-03 18:21:20,558 client 1:  frame 0
2016-11-03 18:21:20,559 client 1:  options={'pts': 0, 'encoding': 'h264', 'type': 'IDR', 'frame': 0, 'delayed': 1, 'csc': 'YUV420P', 'paint': False, 'quality': 58, 'speed': 95}
2016-11-03 18:21:20,559 client 1:  decoder state:
2016-11-03 18:21:20,560 client 1:   decoder_height = 480
2016-11-03 18:21:20,561 client 1:   encoding = h264
2016-11-03 18:21:20,562 client 1:   colorspace = YUV420P
2016-11-03 18:21:20,563 client 1:   actual_colorspace = YUV420P
2016-11-03 18:21:20,563 client 1:   height = 480
2016-11-03 18:21:20,563 client 1:   decoder_width = 854
2016-11-03 18:21:20,563 client 1:   width = 854
2016-11-03 18:21:20,563 client 1:   version = (57, 48, 101)
2016-11-03 18:21:20,564 client 1:   formats = ['YUV422P', 'BGRX', 'GBRP', 'RGB', 'YUV420P', 'BGRA', 'ARGB', 'XRGB', 'YUV444P']
2016-11-03 18:21:20,564 client 1:   frames = 0
2016-11-03 18:21:20,564 client 1:   type = avcodec
2016-11-03 18:21:20,565 client 1: record_decode_time(True, ) wid=2, h264: 854x480, 12.1ms
2016-11-03 18:21:20,565 client 1: after_draw_refresh(True, ) 854x480 at 147x150 encoding=h264, options={'pts': 0, 'encoding': 'h264', 'type': 'IDR', 'frame': 0, 'delayed': 1, 'csc': 'YUV420P', 'paint': False, 'quality': 58, 'speed': 95}
2016-11-03 18:21:20,632 x264 encode YUV420P frame     1 as    P slice with 4 nals, tune=film, total    6796 bytes, keyframe=False, delayed=1
2016-11-03 18:21:20,633 compress:  22.2ms for  854x480  pixels at  147,150  for wid=2     using  h264 with ratio   0.4% ( 1601KB to     6KB), sequence  1773, client_options={'pts': 41, 'frame': 1, 'delayed': 1, 'csc': 'YUV420P', 'type': 'P', 'quality': 58, 'speed': 95}
2016-11-03 18:21:20,637 client 1: draw_region(147, 150, 854, 480, h264, 6796 bytes, 0, {'speed': 95, 'type': 'P', 'pts': 41, 'frame': 1, 'quality': 58, 'delayed': 1, 'csc': 'YUV420P'}, [<function record_decode_time at 0x10861df0>, <function after_draw_refresh at 0x10861870>])
2016-11-03 18:21:20,639 client 1: gl_paint_planar(0, 'h264', AVImageWrapper-None(YUV420P:(0, 0, 854, 480, 24):3_PLANES), 147, 150, 854, 480, 854, 480, [<function record_decode_time at 0x10861df0>, <function after_draw_refresh at 0x10861870>])
2016-11-03 18:21:20,641 client 1: gtk2.GLWindowBacking(2, (1589, 1026), GBRP).gl_context() GL Pixmap backing size: 1589 x 1026, context=gtk2.GLContextManager(<gtk.DrawingArea object at 0xb85d418 (GtkDrawingArea at 0x49ffb58)>)
2016-11-03 18:21:20,641 client 1: gtk2.GLWindowBacking(2, (1589, 1026), GBRP).update_planar_textures(147, 150, 854, 480, AVImageWrapper-None(YUV420P:(0, 0, 854, 480, 24):3_PLANES), 'YUV420P')
2016-11-03 18:21:20,642 client 1: Creating new planar textures, pixel format YUV420P
2016-11-03 18:21:20,642 client 1: updating planar textures: 854x480 YUV420P
2016-11-03 18:21:20,642 client 1: texture 0: div=(1, 1), rowstride=896, 854x480, data=430080 bytes, upload=zerocopy:buffer-as-memoryview
2016-11-03 18:21:20,642 client 1: texture 1: div=(2, 2), rowstride=448, 427x240, data=107520 bytes, upload=zerocopy:buffer-as-memoryview
2016-11-03 18:21:20,643 client 1: texture 2: div=(2, 2), rowstride=448, 427x240, data=107520 bytes, upload=zerocopy:buffer-as-memoryview
2016-11-03 18:21:20,644 client 1: gtk2.GLWindowBacking(2, (1589, 1026), YUV420P).render_planar_update(147, 150, 854, 480, 1, 1) pixel_format=YUV420P
2016-11-03 18:21:20,645 client 1: painting planar update, format YUV420P
2016-11-03 18:21:20,646 client 1: gtk2.GLWindowBacking(2, (1589, 1026), YUV420P).render_planar_update(..) texture_size=(854, 480), size=(1589, 1026)
2016-11-03 18:21:20,647 client 1: present_fbo: adding (147, 150, 854, 480) to pending paint list (size=0), flush=0, paint_screen=True
2016-11-03 18:21:20,647 client 1: Presenting FBO on screen
2016-11-03 18:21:20,647 client 1: Switching to RGB paint state
2016-11-03 18:21:20,650 client 1: do_present_fbo: painting [(147, 150, 854, 480)]
2016-11-03 18:21:20,651 client 1: gtk2.GLWindowBacking(2, (1589, 1026), YUV420P).gl_show() flushing
2016-11-03 18:21:20,651 client 1: gl_show after 118ms took  0ms,  1 updates
2016-11-03 18:21:20,651 client 1: gtk2.GLWindowBacking(2, (1589, 1026), YUV420P).gl_frame_terminator()
2016-11-03 18:21:20,652 client 1: Switching back to YUV paint state
2016-11-03 18:21:20,652 client 1: <OpenGL.platform.baseplatform.glBindFramebuffer object at 0xbf374f0>(GL_FRAMEBUFFER (36160), c_ulong(1L))
2016-11-03 18:21:20,652 client 1: gtk2.GLWindowBacking(2, (1589, 1026), YUV420P).do_present_fbo() done
2016-11-03 18:21:20,652 client 1: record_decode_time(True, ) wid=2, h264: 854x480, 11.1ms
2016-11-03 18:21:20,653 client 1: after_draw_refresh(True, ) 854x480 at 147x150 encoding=h264, options={'speed': 95, 'type': 'P', 'pts': 41, 'frame': 1, 'encoding': 'h264', 'quality': 58, 'delayed': 1, 'csc': 'YUV420P'}

Tried to also run with XPRA_X264_SLICED_THREADS=0 as a sole environment variable, which produced a different error entirely...

2016-11-03 18:42:57,239 compress:   0.8ms for 1589x150  pixels at    0,0    for wid=2     using rgb24 with ratio   2.6% (  931KB to    23KB), sequence   295, client_options={'lz4': 1, 'rgb_format': 'BGRX'}
2016-11-03 18:42:57,259 client 1: draw_region(0, 633, 1589, 393, rgb24, 258285 bytes, 6356, {'flush': 3, 'lz4': 1, 'rgb_format': 'BGRX'}, [<function record_decode_time at 0x85f04b0>, <function after_draw_refresh at 0x85f0670>])
2016-11-03 18:42:57,265 client 1: draw_region(147, 340, 854, 4, png, 435 bytes, 0, {'av-sync': True}, [<function record_decode_time at 0x85f0530>, <function after_draw_refresh at 0x85f08f0>])
2016-11-03 18:42:57,266 client 1: gtk2.GLWindowBacking(2, (1589, 1026), None).do_paint_rgb(BGRX, 2497908 bytes, x=0, y=633, width=1589, height=393, rowstride=6356, options={'encoding': 'rgb24', 'flush': 3, 'lz4': 1, 'rgb_format': 'BGRX'})
2016-11-03 18:42:57,266 client 1: gtk2.GLWindowBacking(2, (1589, 1026), None).gl_context() GL Pixmap backing size: 1589 x 1026, context=gtk2.GLContextManager(<gtk.DrawingArea object at 0x8676418 (GtkDrawingArea at 0x916b58)>)
2016-11-03 18:42:57,267 client 1: Switching to RGB paint state
2016-11-03 18:42:57,268 client 1: BGRX update at (0,633) size 1589x393 (2497908 bytes), stride=6356, row length 0, alignment 4, using GL zerocopy:buffer-as-memoryview format=BGRA
2016-11-03 18:42:57,268 client 1: present_fbo: adding (0, 633, 1589, 393) to pending paint list (size=0), flush=3, paint_screen=True
2016-11-03 18:42:57,269 client 1: record_decode_time(True, ) wid=2, rgb24: 1589x393, 7.3ms
2016-11-03 18:42:57,270 client 1: after_draw_refresh(True, ) 1589x393 at 0x633 encoding=rgb24, options={'encoding': 'rgb24', 'flush': 3, 'lz4': 1, 'rgb_format': 'BGRX'}
2016-11-03 18:42:57,270 client 1: gtk2.GLWindowBacking(2, (1589, 1026), None).do_paint_rgb(RGB, 10248 bytes, x=147, y=340, width=854, height=4, rowstride=2562, options={'av-sync': True, 'rgb_format': 'RGB', 'encoding': 'png'})
2016-11-03 18:42:57,271 client 1: gtk2.GLWindowBacking(2, (1589, 1026), None).gl_context() GL Pixmap backing size: 1589 x 1026, context=gtk2.GLContextManager(<gtk.DrawingArea object at 0x8676418 (GtkDrawingArea at 0x916b58)>)
2016-11-03 18:42:57,278 client 1: Switching to RGB paint state
2016-11-03 18:42:57,279 client 1: RGB update at (147,340) size 854x4 (10248 bytes), stride=2562, row length 0, alignment 2, using GL zerocopy:buffer-as-memoryview format=RGB
2016-11-03 18:42:57,280 client 1: present_fbo: adding (147, 340, 854, 4) to pending paint list (size=1), flush=0, paint_screen=True
2016-11-03 18:42:57,281 client 1: Presenting FBO on screen
2016-11-03 18:42:57,282 client 1: Switching to RGB paint state
2016-11-03 18:42:57,282 client 1: do_present_fbo: painting [(0, 633, 1589, 393), (147, 340, 854, 4)]
2016-11-03 18:42:57,283 client 1: gtk2.GLWindowBacking(2, (1589, 1026), None).gl_show() flushing
2016-11-03 18:42:57,284 client 1: gl_show after  68ms took  1ms,  2 updates
2016-11-03 18:42:57,284 client 1: gtk2.GLWindowBacking(2, (1589, 1026), None).gl_frame_terminator()
2016-11-03 18:42:57,285 client 1: Switching back to YUV paint state
2016-11-03 18:42:57,285 client 1: <OpenGL.platform.baseplatform.glBindFramebuffer object at 0xb6554f0>(GL_FRAMEBUFFER (36160), c_ulong(2L))
2016-11-03 18:42:57,286 client 1: gtk2.GLWindowBacking(2, (1589, 1026), None).do_present_fbo() done
2016-11-03 18:42:57,286 client 1: record_decode_time(True, ) wid=2, png: 854x4, 18.5ms
2016-11-03 18:42:57,287 client 1: after_draw_refresh(True, ) 854x4 at 147x340 encoding=png, options={'av-sync': True, 'encoding': 'png'}
2016-11-03 18:42:57,290 client 1: draw_region(1001, 150, 588, 483, rgb24, 200853 bytes, 2352, {'flush': 2, 'lz4': 1, 'rgb_format': 'BGRX'}, [<function record_decode_time at 0x85f0530>, <function after_draw_refresh at 0x85f08f0>])
2016-11-03 18:42:57,291 client 1: draw_region(0, 150, 147, 483, rgb24, 1131 bytes, 588, {'flush': 1, 'lz4': 1, 'rgb_format': 'BGRX'}, [<function record_decode_time at 0x85f0670>, <function after_draw_refresh at 0x85f0a70>])
2016-11-03 18:42:57,292 client 1: gtk2.GLWindowBacking(2, (1589, 1026), None).do_paint_rgb(BGRX, 1136016 bytes, x=1001, y=150, width=588, height=483, rowstride=2352, options={'encoding': 'rgb24', 'flush': 2, 'lz4': 1, 'rgb_format': 'BGRX'})
2016-11-03 18:42:57,292 client 1: gtk2.GLWindowBacking(2, (1589, 1026), None).gl_context() GL Pixmap backing size: 1589 x 1026, context=gtk2.GLContextManager(<gtk.DrawingArea object at 0x8676418 (GtkDrawingArea at 0x916b58)>)
2016-11-03 18:42:57,293 client 1: Switching to RGB paint state
2016-11-03 18:42:57,294 client 1: BGRX update at (1001,150) size 588x483 (1136016 bytes), stride=2352, row length 0, alignment 8, using GL zerocopy:buffer-as-memoryview format=BGRA
2016-11-03 18:42:57,295 client 1: present_fbo: adding (1001, 150, 588, 483) to pending paint list (size=0), flush=2, paint_screen=True
2016-11-03 18:42:57,296 client 1: record_decode_time(True, ) wid=2, rgb24: 588x483, 3.4ms
2016-11-03 18:42:57,297 client 1: after_draw_refresh(True, ) 588x483 at 1001x150 encoding=rgb24, options={'encoding': 'rgb24', 'flush': 2, 'lz4': 1, 'rgb_format': 'BGRX'}
2016-11-03 18:42:57,298 client 1: gtk2.GLWindowBacking(2, (1589, 1026), None).do_paint_rgb(BGRX, 284004 bytes, x=0, y=150, width=147, height=483, rowstride=588, options={'encoding': 'rgb24', 'flush': 1, 'lz4': 1, 'rgb_format': 'BGRX'})
2016-11-03 18:42:57,298 client 1: gtk2.GLWindowBacking(2, (1589, 1026), None).gl_context() GL Pixmap backing size: 1589 x 1026, context=gtk2.GLContextManager(<gtk.DrawingArea object at 0x8676418 (GtkDrawingArea at 0x916b58)>)
2016-11-03 18:42:57,299 client 1: Switching to RGB paint state
2016-11-03 18:42:57,299 client 1: BGRX update at (0,150) size 147x483 (284004 bytes), stride=588, row length 0, alignment 4, using GL zerocopy:buffer-as-memoryview format=BGRA
2016-11-03 18:42:57,299 client 1: present_fbo: adding (0, 150, 147, 483) to pending paint list (size=1), flush=1, paint_screen=True
2016-11-03 18:42:57,299 client 1: record_decode_time(True, ) wid=2, rgb24: 147x483, 5.9ms
2016-11-03 18:42:57,300 client 1: after_draw_refresh(True, ) 147x483 at 0x150 encoding=rgb24, options={'encoding': 'rgb24', 'flush': 1, 'lz4': 1, 'rgb_format': 'BGRX'}
2016-11-03 18:42:57,300 client 1: draw_region(0, 0, 1589, 150, rgb24, 24319 bytes, 6356, {'lz4': 1, 'rgb_format': 'BGRX'}, [<function record_decode_time at 0x85f0670>, <function after_draw_refresh at 0x85f0a70>])
2016-11-03 18:42:57,300 client 1: gtk2.GLWindowBacking(2, (1589, 1026), None).do_paint_rgb(BGRX, 953400 bytes, x=0, y=0, width=1589, height=150, rowstride=6356, options={'encoding': 'rgb24', 'lz4': 1, 'rgb_format': 'BGRX'})
2016-11-03 18:42:57,300 client 1: gtk2.GLWindowBacking(2, (1589, 1026), None).gl_context() GL Pixmap backing size: 1589 x 1026, context=gtk2.GLContextManager(<gtk.DrawingArea object at 0x8676418 (GtkDrawingArea at 0x916b58)>)
2016-11-03 18:42:57,301 client 1: Switching to RGB paint state
2016-11-03 18:42:57,301 client 1: BGRX update at (0,0) size 1589x150 (953400 bytes), stride=6356, row length 0, alignment 4, using GL zerocopy:buffer-as-memoryview format=BGRA
2016-11-03 18:42:57,302 client 1: present_fbo: adding (0, 0, 1589, 150) to pending paint list (size=2), flush=0, paint_screen=True
2016-11-03 18:42:57,302 client 1: Presenting FBO on screen
2016-11-03 18:42:57,304 client 1: Switching to RGB paint state
2016-11-03 18:42:57,307 client 1: do_present_fbo: painting [(1001, 150, 588, 483), (0, 150, 147, 483), (0, 0, 1589, 150)]
2016-11-03 18:42:57,308 client 1: gtk2.GLWindowBacking(2, (1589, 1026), None).gl_show() flushing
2016-11-03 18:42:57,309 client 1: gl_show after  31ms took  3ms,  3 updates
2016-11-03 18:42:57,310 client 1: gtk2.GLWindowBacking(2, (1589, 1026), None).gl_frame_terminator()
2016-11-03 18:42:57,311 client 1: Switching back to YUV paint state
2016-11-03 18:42:57,312 client 1: <OpenGL.platform.baseplatform.glBindFramebuffer object at 0xb6554f0>(GL_FRAMEBUFFER (36160), c_ulong(2L))
2016-11-03 18:42:57,313 client 1: gtk2.GLWindowBacking(2, (1589, 1026), None).do_present_fbo() done
2016-11-03 18:42:57,314 client 1: record_decode_time(True, ) wid=2, rgb24: 1589x150, 11.0ms
2016-11-03 18:42:57,314 client 1: after_draw_refresh(True, ) 1589x150 at 0x0 encoding=rgb24, options={'encoding': 'rgb24', 'lz4': 1, 'rgb_format': 'BGRX'}
2016-11-03 18:42:57,888 Error: failed to encode x264 video frame:
2016-11-03 18:42:57,889  x264_encoder_encode produced no data (frame=0, frame-size=0, b-frames=0, delayed-frames=2)
2016-11-03 18:42:57,889  source: XShmImageWrapper(BGRX: 147, 150, 854, 483)
2016-11-03 18:42:57,889  options: {'av-sync': True}
2016-11-03 18:42:57,889  encoder:
2016-11-03 18:42:57,889    profile             : high444
2016-11-03 18:42:57,890    generation          : 12
2016-11-03 18:42:57,890    delayed             : 2
2016-11-03 18:42:57,890    height              : 482
2016-11-03 18:42:57,890    max-size            : (8192, 4096)
2016-11-03 18:42:57,890    preset              : superfast
2016-11-03 18:42:57,890    frames              : 0
2016-11-03 18:42:57,891    quality             : 50
2016-11-03 18:42:57,891    lossless            : False
2016-11-03 18:42:57,891    frame-types         : {}
2016-11-03 18:42:57,891    width               : 854
2016-11-03 18:42:57,892    speed               : 93
2016-11-03 18:42:57,892    source              : unknown
2016-11-03 18:42:57,892    version             : 148
2016-11-03 18:42:57,893    tune                : zerolatency
2016-11-03 18:42:57,893    src_format          : BGRX
2016-11-03 18:42:57,893    formats             : ['YUV422P', 'RGB', 'BGRX', 'BGR', 'YUV420P', 'BGRA', 'YUV444P']
2016-11-03 18:42:57,893    b-frames            : 0
2016-11-03 18:42:57,893    buffer_api          : 1
2016-11-03 18:42:57,954 Error: failed to encode x264 video frame:
2016-11-03 18:42:57,954  x264_encoder_encode produced no data (frame=0, frame-size=0, b-frames=0, delayed-frames=3)
2016-11-03 18:42:57,954  source: XShmImageWrapper(BGRX: 147, 150, 854, 483)
2016-11-03 18:42:57,954  options: {'av-sync': True}
2016-11-03 18:42:57,955  encoder:
2016-11-03 18:42:57,955    profile             : high444
2016-11-03 18:42:57,955    generation          : 12
2016-11-03 18:42:57,955    delayed             : 3
2016-11-03 18:42:57,956    height              : 482
2016-11-03 18:42:57,956    max-size            : (8192, 4096)
2016-11-03 18:42:57,956    preset              : superfast
2016-11-03 18:42:57,957    frames              : 0
2016-11-03 18:42:57,957    quality             : 50
2016-11-03 18:42:57,957    lossless            : False
2016-11-03 18:42:57,957    frame-types         : {}
2016-11-03 18:42:57,957    width               : 854
2016-11-03 18:42:57,958    speed               : 93
2016-11-03 18:42:57,958    source              : unknown
2016-11-03 18:42:57,958    version             : 148
2016-11-03 18:42:57,958    tune                : zerolatency
2016-11-03 18:42:57,958    src_format          : BGRX
2016-11-03 18:42:57,958    formats             : ['YUV422P', 'RGB', 'BGRX', 'BGR', 'YUV420P', 'BGRA', 'YUV444P']
2016-11-03 18:42:57,959    b-frames            : 0
2016-11-03 18:42:57,959    buffer_api          : 1
2016-11-03 18:42:58,009 Error: failed to encode x264 video frame:
2016-11-03 18:42:58,009  x264_encoder_encode produced no data (frame=0, frame-size=0, b-frames=0, delayed-frames=4)
2016-11-03 18:42:58,009  source: XShmImageWrapper(BGRX: 147, 150, 854, 483)
2016-11-03 18:42:58,010  options: {'av-sync': True}
2016-11-03 18:42:58,010  encoder:
2016-11-03 18:42:58,010    profile             : high444
2016-11-03 18:42:58,010    generation          : 12
2016-11-03 18:42:58,010    delayed             : 4
2016-11-03 18:42:58,011    height              : 482
2016-11-03 18:42:58,011    max-size            : (8192, 4096)
2016-11-03 18:42:58,011    preset              : superfast
2016-11-03 18:42:58,011    frames              : 0
2016-11-03 18:42:58,011    quality             : 50
2016-11-03 18:42:58,011    lossless            : False
2016-11-03 18:42:58,012    frame-types         : {}
2016-11-03 18:42:58,013    width               : 854
2016-11-03 18:42:58,014    speed               : 93
2016-11-03 18:42:58,014    source              : unknown
2016-11-03 18:42:58,014    version             : 148
2016-11-03 18:42:58,015    tune                : zerolatency
2016-11-03 18:42:58,015    src_format          : BGRX
2016-11-03 18:42:58,015    formats             : ['YUV422P', 'RGB', 'BGRX', 'BGR', 'YUV420P', 'BGRA', 'YUV444P']
2016-11-03 18:42:58,015    b-frames            : 0
2016-11-03 18:42:58,016    buffer_api          : 1
2016-11-03 18:42:58,091 Error: failed to encode x264 video frame:
2016-11-03 18:42:58,092  x264_encoder_encode produced no data (frame=0, frame-size=0, b-frames=0, delayed-frames=5)
2016-11-03 18:42:58,092  source: XShmImageWrapper(BGRX: 147, 150, 854, 483)
2016-11-03 18:42:58,092  options: {'av-sync': True}
2016-11-03 18:42:58,092  encoder:
2016-11-03 18:42:58,092    profile             : high444
2016-11-03 18:42:58,092    generation          : 12
2016-11-03 18:42:58,092    delayed             : 5
2016-11-03 18:42:58,092    height              : 482
2016-11-03 18:42:58,093    max-size            : (8192, 4096)
2016-11-03 18:42:58,093    preset              : superfast
2016-11-03 18:42:58,093    frames              : 0
2016-11-03 18:42:58,093    quality             : 50
2016-11-03 18:42:58,093    lossless            : False
2016-11-03 18:42:58,093    frame-types         : {}
2016-11-03 18:42:58,093    width               : 854
2016-11-03 18:42:58,093    speed               : 93
2016-11-03 18:42:58,093    source              : unknown
2016-11-03 18:42:58,093    version             : 148
2016-11-03 18:42:58,093    tune                : zerolatency
2016-11-03 18:42:58,093    src_format          : BGRX
2016-11-03 18:42:58,094    formats             : ['YUV422P', 'RGB', 'BGRX', 'BGR', 'YUV420P', 'BGRA', 'YUV444P']
2016-11-03 18:42:58,094    b-frames            : 0
2016-11-03 18:42:58,094    buffer_api          : 1
2016-11-03 18:42:58,155 x264 encode    BGRX frame     0 as  IDR slice with 4 nals, tune=zerolatency, total   11851 bytes, keyframe=True , delayed=5
2016-11-03 18:42:58,156 compress:   9.9ms for  854x482  pixels at  147,150  for wid=2     using  h264 with ratio   0.7% ( 1611KB to    11KB), sequence   296, client_options={'pts': 0, 'frame': 0, 'delayed': 5, 'csc': 'YUV444P', 'type': 'IDR', 'quality': 50, 'speed': 94}

... which makes me suspect that both of those environment variables are required to deal with the errors... though I haven't yet tested with just the other disabled.

totaam · 2016-11-04T12:11:21Z

2016-11-04 12:11:21: antoine changed owner from antoine to afarr

totaam · 2016-11-04T12:11:21Z

2016-11-04 12:11:21: antoine commented

Sorry about that, it's all quite embarrassing:

XPRA_B_FRAMES=0 was not being honoured (quickly spotted because your output had b-frames=1 for the x264 encoder, that's fixed in r14392

the "Resource temporarily unavailable" was specific to OSX clients, that's fixed in r14393

the XPRA_X264_SLICED_THREADS=0 errors I can reproduce very easily - I'm not sure why that breaks (maybe we just can't use frame threading without b-frames?), and we don't care - let's just avoid changing this setting for now

also fixed some errors in the client code that were found thanks to the new code that landed in wishlist: Support multiple clients connected at the same time #41: r14394 (unnecessary repaints with opengl)

I believe those errors should now all be gone - though I don't doubt for one second your ability to turn up some more.

totaam · 2016-11-08T02:11:44Z

2016-11-08 02:11:44: afarr changed owner from afarr to antoine

totaam · 2016-11-08T02:11:44Z

2016-11-08 02:11:44: afarr commented

Well... re-tested with 1.0 r14155 osx client (again... might check into our capability to build for ourselves soon) against a newly built 1.0 r14399 fedora 23 server.

The good news is that, with XPRA_B_FRAMES=0... I'm no longer seeing any sign of the avcodec errors.

The (possibly equally good?) other news is that, without that environment variable I am still... eventually... able to repro (usually by scrolling and mousing madly over a browser tab playing video, then getting up to get a snack or beverage... by the time I'm back, I've got an error in logs, though obviously haven't seen anything).

Server-side, without disabling B-Frames... with -d stat,x264,compress...

...
2016-11-07 17:36:54,679 x264 close context 0x0
2016-11-07 17:36:54,686 x264 encode 1 delayed frames after 0
2016-11-07 17:36:54,692 compress:  26.0ms for  854x480  pixels at  147,150  for wid=2     using  jpeg with ratio   1.2% ( 1601KB to    19KB), sequence  8335, client_options={'quality': 70}
2016-11-07 17:36:54,702 x264 encode YUV420P frame     0 as  IDR slice with 7 nals, tune=film, total    6772 bytes, keyframe=True , delayed=1
2016-11-07 17:36:54,702 compress:  10.2ms for  854x480  pixels at  147,150  for wid=2     using  h264 with ratio   0.4% ( 1601KB to     6KB), sequence  8336, client_options={'pts': 0, 'frame': 0, 'delayed': 1, 'csc': 'YUV420P', 'paint': False, 'type': 'IDR', 'quality': 30, 'speed': 96}
2016-11-07 17:36:54,716 x264 encode YUV420P frame     1 as    P slice with 4 nals, tune=film, total     497 bytes, keyframe=False, delayed=1
2016-11-07 17:36:54,717 compress:  13.9ms for  854x480  pixels at  147,150  for wid=2     using  h264 with ratio   0.0% ( 1601KB to     0KB), sequence  8337, client_options={'pts': 23, 'frame': 1, 'delayed': 1, 'csc': 'YUV420P', 'type': 'P', 'quality': 30, 'speed': 96}
2016-11-07 17:36:54,717 rgb_encode using level=0, not compressed 256x174 in rgb24/BGRX: 178176 bytes down to 178176
2016-11-07 17:36:54,718 compress:   0.9ms for  256x174  pixels at  508,852  for wid=2     using rgb24 with ratio 100.0% (  174KB to   174KB), sequence  8338, client_options={'rgb_format': 'BGRX'}
2016-11-07 17:36:54,728 x264 encode YUV420P frame     2 as    B slice with 4 nals, tune=film, total     105 bytes, keyframe=False, delayed=1
2016-11-07 17:36:54,728 compress:   9.9ms for  854x480  pixels at  147,150  for wid=2     using  h264 with ratio   0.0% ( 1601KB to     0KB), sequence  8339, client_options={'pts': 12, 'frame': 2, 'delayed': 1, 'csc': 'YUV420P', 'type': 'B', 'quality': 30, 'speed': 96}
2016-11-07 17:36:54,739 client 1: Error: avcodec error -35 decoding 6772 bytes of h264 data:
2016-11-07 17:36:54,740 client 1:  'Resource temporarily unavailable'
2016-11-07 17:36:54,740 client 1:  frame 0
2016-11-07 17:36:54,741 client 1:  options={'pts': 0, 'encoding': 'h264', 'type': 'IDR', 'frame': 0, 'delayed': 1, 'csc': 'YUV420P', 'paint': False, 'quality': 30, 'speed': 96}
2016-11-07 17:36:54,741 client 1:  decoder state:
2016-11-07 17:36:54,741 client 1:   decoder_height = 480
2016-11-07 17:36:54,742 client 1:   encoding = h264
2016-11-07 17:36:54,742 client 1:   colorspace = YUV420P
2016-11-07 17:36:54,743 client 1:   actual_colorspace = YUV420P
2016-11-07 17:36:54,743 client 1:   height = 480
2016-11-07 17:36:54,743 client 1:   decoder_width = 854
2016-11-07 17:36:54,744 x264 encode YUV420P frame     3 as    P slice with 4 nals, tune=film, total     947 bytes, keyframe=False, delayed=1
2016-11-07 17:36:54,744 client 1:   width = 854
2016-11-07 17:36:54,745 compress:  16.0ms for  854x480  pixels at  147,150  for wid=2     using  h264 with ratio   0.1% ( 1601KB to     0KB), sequence  8340, client_options={'pts': 53, 'frame': 3, 'delayed': 1, 'csc': 'YUV420P', 'type': 'P', 'quality': 30, 'speed': 96}
2016-11-07 17:36:54,745 client 1:   version = (57, 48, 101)
2016-11-07 17:36:54,746 client 1:   formats = ['YUV422P', 'BGRX', 'GBRP', 'RGB', 'YUV420P', 'BGRA', 'ARGB', 'XRGB', 'YUV444P']
2016-11-07 17:36:54,746 client 1:   frames = 0
2016-11-07 17:36:54,747 client 1:   type = avcodec
2016-11-07 17:36:54,755 x264 encode YUV420P frame     4 as    B slice with 4 nals, tune=film, total      76 bytes, keyframe=False, delayed=1
2016-11-07 17:36:54,755 compress:   9.4ms for  854x480  pixels at  147,150  for wid=2     using  h264 with ratio   0.0% ( 1601KB to     0KB), sequence  8341, client_options={'pts': 39, 'frame': 4, 'delayed': 1, 'csc': 'YUV420P', 'type': 'B', 'quality': 30, 'speed': 96}
2016-11-07 17:36:54,766 x264 encode YUV420P frame     5 as    P slice with 4 nals, tune=film, total    1849 bytes, keyframe=False, delayed=1
2016-11-07 17:36:54,767 compress:  11.1ms for  854x480  pixels at  147,150  for wid=2     using  h264 with ratio   0.1% ( 1601KB to     1KB), sequence  8342, client_options={'pts': 76, 'frame': 5, 'delayed': 1, 'csc': 'YUV420P', 'type': 'P', 'quality': 30, 'speed': 96}
2016-11-07 17:36:54,774 x264 encode YUV420P frame     6 as    B slice with 4 nals, tune=film, total     115 bytes, keyframe=False, delayed=1
2016-11-07 17:36:54,775 compress:   7.7ms for  854x480  pixels at  147,150  for wid=2     using  h264 with ratio   0.0% ( 1601KB to     0KB), sequence  8343, client_options={'pts': 66, 'frame': 6, 'delayed': 1, 'csc': 'YUV420P', 'type': 'B', 'quality': 30, 'speed': 96}
2016-11-07 17:36:54,785 x264 encode YUV420P frame     7 as    P slice with 4 nals, tune=film, total    1255 bytes, keyframe=False, delayed=1
2016-11-07 17:36:54,786 compress:  10.4ms for  854x480  pixels at  147,150  for wid=2     using  h264 with ratio   0.1% ( 1601KB to     1KB), sequence  8344, client_options={'pts': 95, 'frame': 7, 'delayed': 1, 'csc': 'YUV420P', 'type': 'P', 'quality': 30, 'speed': 96}
2016-11-07 17:36:54,796 x264 encode YUV420P frame     8 as    B slice with 4 nals, tune=film, total      79 bytes, keyframe=False, delayed=1
...

I assume having the error show up whenever b-frames are enabled isn't a place to close this, so I'll hand it back to you.

totaam · 2016-11-09T06:10:59Z

2016-11-09 06:10:59: antoine changed owner from antoine to afarr

totaam · 2016-11-09T06:10:59Z

2016-11-09 06:10:59: antoine commented

Please re-test with an up to date client, the client 1: Error: avcodec error -35 decoding 6772 bytes of h264 data.. error was fixed in r14393.

totaam · 2016-11-12T00:05:48Z

2016-11-12 00:05:48: afarr changed owner from afarr to antoine

totaam · 2016-11-12T00:05:48Z

2016-11-12 00:05:48: afarr commented

Tried to re-test with 1.0 r14397 osx client, against 1.0 r14404 fedora 23 server... but client wouldn't launch (#1355 missing dyld library).

Tried to re-retest with 1.0 r14397 win client, with intel 4000 graphics and --opengl=on forced... added some new opengl error messages to the end of #1111.

Testing with 1.0 r14397 win client without OpenGL... I no longer see any avcodec errors.

I'll pass this back to help ensure you glance at the errors added to #1111 to be sure there's nothing new there... and if the opengl isn't liable to impact the avcodec potential issues, then this can probably be closed.

totaam · 2016-11-13T11:18:11Z

2016-11-13 11:18:11: antoine changed status from new to closed

totaam · 2016-11-13T11:18:11Z

2016-11-13 11:18:11: antoine set resolution to fixed

totaam · 2016-11-13T11:18:11Z

2016-11-13 11:18:11: antoine commented

opengl or not shouldn't make any difference, so closing.

totaam closed this as completed Nov 13, 2016

totaam mentioned this issue Nov 10, 2021

html5 client improvements: refactoring, mpeg4, scrolling, etc #1341

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Seeing avcodec errors when playing video #1346

Seeing avcodec errors when playing video #1346

totaam commented Oct 26, 2016

totaam commented Oct 26, 2016

totaam commented Oct 26, 2016

totaam commented Oct 26, 2016

totaam commented Oct 26, 2016

totaam commented Oct 27, 2016

totaam commented Oct 27, 2016

totaam commented Oct 27, 2016

totaam commented Oct 27, 2016

totaam commented Oct 27, 2016

totaam commented Oct 27, 2016

totaam commented Oct 27, 2016

totaam commented Nov 2, 2016

totaam commented Nov 2, 2016

totaam commented Nov 2, 2016

totaam commented Nov 2, 2016

totaam commented Nov 2, 2016

totaam commented Nov 4, 2016

totaam commented Nov 4, 2016

totaam commented Nov 4, 2016

totaam commented Nov 4, 2016

totaam commented Nov 8, 2016

totaam commented Nov 8, 2016

totaam commented Nov 9, 2016

totaam commented Nov 9, 2016

totaam commented Nov 12, 2016

totaam commented Nov 12, 2016

totaam commented Nov 13, 2016

totaam commented Nov 13, 2016

totaam commented Nov 13, 2016

Seeing avcodec errors when playing video #1346

Seeing avcodec errors when playing video #1346

Comments

totaam commented Oct 26, 2016

2016-10-26 01:18:13: afarr created the issue

totaam commented Oct 26, 2016

2016-10-26 02:20:48: afarr commented

totaam commented Oct 26, 2016

2016-10-26 09:07:10: antoine changed owner from antoine to afarr

totaam commented Oct 26, 2016

2016-10-26 09:07:10: antoine edited the issue description

totaam commented Oct 26, 2016

2016-10-26 09:07:10: antoine commented

totaam commented Oct 27, 2016

2016-10-27 00:48:55: afarr changed owner from afarr to antoine

totaam commented Oct 27, 2016

2016-10-27 00:48:55: afarr commented

totaam commented Oct 27, 2016

2016-10-27 06:47:55: antoine changed status from new to assigned

totaam commented Oct 27, 2016

2016-10-27 06:47:55: antoine commented

totaam commented Oct 27, 2016

2016-10-27 10:26:21: antoine changed status from assigned to new

totaam commented Oct 27, 2016

2016-10-27 10:26:21: antoine changed owner from antoine to afarr

totaam commented Oct 27, 2016

2016-10-27 10:26:21: antoine commented

totaam commented Nov 2, 2016

2016-11-02 00:40:29: afarr changed owner from afarr to antoine

totaam commented Nov 2, 2016

2016-11-02 00:40:29: afarr commented

totaam commented Nov 2, 2016

2016-11-02 00:52:05: afarr commented

totaam commented Nov 2, 2016

2016-11-02 04:06:23: antoine changed owner from antoine to afarr

totaam commented Nov 2, 2016

2016-11-02 04:06:23: antoine commented

totaam commented Nov 4, 2016

2016-11-04 01:55:49: afarr changed owner from afarr to antoine

totaam commented Nov 4, 2016

2016-11-04 01:55:49: afarr commented

totaam commented Nov 4, 2016

2016-11-04 12:11:21: antoine changed owner from antoine to afarr

totaam commented Nov 4, 2016

2016-11-04 12:11:21: antoine commented

totaam commented Nov 8, 2016

2016-11-08 02:11:44: afarr changed owner from afarr to antoine

totaam commented Nov 8, 2016

2016-11-08 02:11:44: afarr commented

totaam commented Nov 9, 2016

2016-11-09 06:10:59: antoine changed owner from antoine to afarr

totaam commented Nov 9, 2016

2016-11-09 06:10:59: antoine commented

totaam commented Nov 12, 2016

2016-11-12 00:05:48: afarr changed owner from afarr to antoine

totaam commented Nov 12, 2016

2016-11-12 00:05:48: afarr commented

totaam commented Nov 13, 2016

2016-11-13 11:18:11: antoine changed status from new to closed

totaam commented Nov 13, 2016

2016-11-13 11:18:11: antoine set resolution to fixed

totaam commented Nov 13, 2016

2016-11-13 11:18:11: antoine commented