Thinking of the html5 client... we've been running with only jpeg enabled, just to keep the packets the client has to process as lean as possible - but we're also getting a lot of blurriness (unsurprisingly) as a result.
It would be nice to also allow a lossless encoding, like rgb, but when we try we end up with so much lossless information initially that the client is very slow to connect.
If we could maybe start the server with a flag to force an encoding, like jpeg, for the initial connection, but then let the heuristics take back over to determine when/where/if to use other encodings (rgb, whatever)... then the html5 client might be a lot more flexible.
I'll attach an info log for what our server looks like at the initial connection (my best guess, not a lot of visibility into which moment of initial connection is best to capture), and another info from a session after things have "settled down".
As you can probably tell from the info logs, in both cases we're using only jpeg (let me know if you need info with other encodings enabled or anything).
Hopefully my capture timing was enlightening.
my best guess of moment of initial connection, xpra info
info after the page elements loaded
(changed ticket title: let's focus on identifying the problem before deciding on a solution)
I need the logs with rgb and png, since that's what shows the problem and also what I have when I run the current html5 client code. Is the problem only with rgb? What about png? How do you quantify it?
I am tempted to wait for the new client code to land before making any changes.
All things considered, I may have to wait until new client code lands before I can get logs with rgb & png as well. I'll see what I can do though, maybe get some logs for you to look at and consider while examining the new code coming in for a landing.
I have seen this, even with the python client, r14355 should fix that. It ensures we don't use plain rgb until we have enough packets to tune the heuristics.
tl;dr: r14355 did it, that works great, closing. Thanks!
EDIT: Setting up a r14479 trunk server, and connecting with an html5 client and a Python client of the same revision, we can do some testing and get some relevant logs:
Right, so running with -d compress,paint,encoding
on the server, and looking at the paint prints upon connecting, here's what the server prints when an html5 client connects:
2016-11-23 14:41:26,215 send_delayed_regions: using full window update 499x316 with jpeg 2016-11-23 14:41:26,216 process_damage_region: wid=1, adding pixel data to encode queue ( 499x316 - jpeg), elapsed time: 51.9 ms, request time: 0.7 ms, frame delay=0ms 2016-11-23 14:41:26,216 make_data_packet: image=XShmImageWrapper(BGRX: 0, 0, 499, 316), damage data: (1, 0, 0, 499, 316, 'jpeg') 2016-11-23 14:41:26,218 compress: 1.6ms for 499x316 pixels at 0,0 for wid=1 using jpeg with ratio 7.4% ( 615KB to 45KB), sequence 1, client_options={'quality': 99} 2016-11-23 14:41:26,249 send_delayed for wid 2, batch delay is 52ms, elapsed time is 77ms 2016-11-23 14:41:26,250 send_delayed_regions: bytes_cost=1083040, bytes_threshold=649209, pixel_count=1082016 2016-11-23 14:41:26,250 send_delayed_regions: using full window update 1248x867 with jpeg 2016-11-23 14:41:26,251 process_damage_region: wid=2, adding pixel data to encode queue (1248x867 - jpeg), elapsed time: 79.1 ms, request time: 1.3 ms, frame delay=0ms 2016-11-23 14:41:26,251 make_data_packet: image=XShmImageWrapper(BGRX: 0, 0, 1248, 867), damage data: (2, 0, 0, 1248, 867, 'jpeg') 2016-11-23 14:41:26,264 compress: 12.8ms for 1248x867 pixels at 0,0 for wid=2 using jpeg with ratio 9.3% ( 4226KB to 391KB), sequence 1, client_options={'quality': 99} 2016-11-23 14:41:26,266 update_encoding_options(False) auto_refresh_encodings=['png', 'rgb32'] 2016-11-23 14:41:26,267 update_encoding_options(False) want_alpha=False, lossless threshold: 74 / 6, small_as_rgb=6082, get_best_encoding=<bound method WindowVideoSource.get_best_encoding_video of WindowVideoSource(1 : (499, 316))> 2016-11-23 14:41:26,267 update_encoding_options(False) csc_encoder=None, video_encoder=None 2016-11-23 14:41:26,344 send_delayed for wid 2, batch delay is 52ms, elapsed time is 77ms 2016-11-23 14:41:26,344 send_delayed_regions: bytes_cost=175872, bytes_threshold=649209, pixel_count=172800 2016-11-23 14:41:26,344 send_delayed_regions: merged=[R(164, 126, 480, 360)], merged_bytes_cost=173824, bytes_cost=175872, merged_pixel_count=172800, pixel_count=172800 2016-11-23 14:41:26,345 process_damage_region: wid=2, adding pixel data to encode queue ( 480x360 - jpeg), elapsed time: 79.2 ms, request time: 0.9 ms, frame delay=0ms 2016-11-23 14:41:26,345 send_delayed_regions: sent 1 regions using ['jpeg']
Looks straightforward, it's printing using jpeg - what we want.
And, here again with the Python client:
2016-11-23 14:44:06,561 send_delayed_regions: using full window update 499x316 with jpeg 2016-11-23 14:44:06,561 process_damage_region: wid=1, adding pixel data to encode queue ( 499x316 - jpeg), elapsed time: 51.6 ms, request time: 0.5 ms, frame delay=0ms 2016-11-23 14:44:06,561 make_data_packet: image=XShmImageWrapper(BGRX: 0, 0, 499, 316), damage data: (1, 0, 0, 499, 316, 'jpeg') 2016-11-23 14:44:06,563 compress: 1.6ms for 499x316 pixels at 0,0 for wid=1 using jpeg with ratio 7.4% ( 615KB to 45KB), sequence 1, client_options={'quality': 99} 2016-11-23 14:44:06,573 update_encoding_options(False) auto_refresh_encodings=['png', 'rgb24', 'rgb32'] 2016-11-23 14:44:06,574 update_encoding_options(False) want_alpha=False, lossless threshold: 74 / 6, small_as_rgb=6082, get_best_encoding=<bound method WindowVideoSource.get_best_encoding_video of WindowVideoSource(1 : (499, 316))> 2016-11-23 14:44:06,574 update_encoding_options(False) csc_encoder=None, video_encoder=None 2016-11-23 14:44:06,596 send_delayed for wid 2, batch delay is 52ms, elapsed time is 77ms 2016-11-23 14:44:06,596 send_delayed_regions: bytes_cost=1083040, bytes_threshold=649209, pixel_count=1082016 2016-11-23 14:44:06,596 send_delayed_regions: using full window update 1248x867 with jpeg 2016-11-23 14:44:06,598 process_damage_region: wid=2, adding pixel data to encode queue (1248x867 - jpeg), elapsed time: 79.3 ms, request time: 1.5 ms, frame delay=0ms 2016-11-23 14:44:06,598 make_data_packet: image=XShmImageWrapper(BGRX: 0, 0, 1248, 867), damage data: (2, 0, 0, 1248, 867, 'jpeg') 2016-11-23 14:44:06,611 compress: 12.8ms for 1248x867 pixels at 0,0 for wid=2 using jpeg with ratio 9.3% ( 4226KB to 391KB), sequence 1, client_options={'quality': 99} 2016-11-23 14:44:06,703 send_delayed for wid 2, batch delay is 52ms, elapsed time is 77ms 2016-11-23 14:44:06,703 send_delayed_regions: bytes_cost=175872, bytes_threshold=649209, pixel_count=172800 2016-11-23 14:44:06,704 send_delayed_regions: merged=[R(164, 126, 480, 360)], merged_bytes_cost=173824, bytes_cost=175872, merged_pixel_count=172800, pixel_count=172800 2016-11-23 14:44:06,705 process_damage_region: wid=2, adding pixel data to encode queue ( 480x360 - jpeg), elapsed time: 79.1 ms, request time: 1.1 ms, frame delay=0ms 2016-11-23 14:44:06,705 send_delayed_regions: sent 1 regions using ['jpeg']
Slightly different, but again, only painting with jpeg upon initial connection.
After the connection settles, the html5 client gets the server to print:
2016-11-23 14:41:26,603 compress: 16.4ms for 480x360 pixels at 164,126 for wid=2 using png with ratio 37.0% ( 675KB to 249KB), sequence 5, client_options={'compress_level': 1} 2016-11-23 14:41:26,652 send_delayed for wid 2, batch delay is 52ms, elapsed time is 52ms 2016-11-23 14:41:26,652 send_delayed_regions: bytes_cost=175872, bytes_threshold=649209, pixel_count=172800 2016-11-23 14:41:26,652 send_delayed_regions: merged=[R(164, 126, 480, 360)], merged_bytes_cost=173824, bytes_cost=175872, merged_pixel_count=172800, pixel_count=172800 2016-11-23 14:41:26,653 process_damage_region: wid=2, adding pixel data to encode queue ( 480x360 - auto), elapsed time: 54.3 ms, request time: 0.9 ms, frame delay=0ms 2016-11-23 14:41:26,653 send_delayed_regions: sent 1 regions using ['auto'] 2016-11-23 14:41:26,653 make_data_packet: image=XShmImageWrapper(BGRX: 164, 126, 480, 360), damage data: (2, 164, 126, 480, 360, 'auto') 2016-11-23 14:41:26,654 <bound method WindowVideoSource.video_encode of WindowVideoSource(2 : (1248, 867))>('auto', XShmImageWrapper(BGRX: 164, 126, 480, 360), {'scroll': True}) returned None 2016-11-23 14:41:26,718 send_delayed for wid 2, batch delay is 52ms, elapsed time is 52ms 2016-11-23 14:41:26,719 send_delayed_regions: bytes_cost=175872, bytes_threshold=649209, pixel_count=172800 2016-11-23 14:41:26,719 send_delayed_regions: merged=[R(164, 126, 480, 360)], merged_bytes_cost=173824, bytes_cost=175872, merged_pixel_count=172800, pixel_count=172800 2016-11-23 14:41:26,720 process_damage_region: wid=2, adding pixel data to encode queue ( 480x360 - auto), elapsed time: 54.0 ms, request time: 0.9 ms, frame delay=0ms 2016-11-23 14:41:26,720 send_delayed_regions: sent 1 regions using ['auto']
Looks like we switched to PNG, expected - not a whole lot going on, only got Chrome open and not even interacting.
And, the same with a Python client connected:
2016-11-23 14:44:06,857 send_delayed_regions: using full window update 499x316 with png 2016-11-23 14:44:06,857 process_damage_region: wid=1, adding pixel data to encode queue ( 499x316 - png), elapsed time: 0.4 ms, request time: 0.1 ms, frame delay=0ms 2016-11-23 14:44:06,857 make_data_packet: image=XShmImageWrapper(BGRX: 0, 0, 499, 316), damage data: (1, 0, 0, 499, 316, 'png') 2016-11-23 14:44:06,865 compress: 7.2ms for 499x316 pixels at 0,0 for wid=1 using png with ratio 1.1% ( 615KB to 7KB), sequence 2, client_options={'compress_level': 3} 2016-11-23 14:44:06,906 send_delayed for wid 2, batch delay is 52ms, elapsed time is 52ms 2016-11-23 14:44:06,906 send_delayed_regions: bytes_cost=175872, bytes_threshold=649209, pixel_count=172800 2016-11-23 14:44:06,906 send_delayed_regions: merged=[R(164, 126, 480, 360)], merged_bytes_cost=173824, bytes_cost=175872, merged_pixel_count=172800, pixel_count=172800 2016-11-23 14:44:06,907 process_damage_region: wid=2, adding pixel data to encode queue ( 480x360 - auto), elapsed time: 54.5 ms, request time: 1.3 ms, frame delay=0ms 2016-11-23 14:44:06,908 send_delayed_regions: sent 1 regions using ['auto'] 2016-11-23 14:44:06,908 make_data_packet: image=XShmImageWrapper(BGRX: 164, 126, 480, 360), damage data: (2, 164, 126, 480, 360, 'auto') 2016-11-23 14:44:06,928 compress: 20.2ms for 480x360 pixels at 164,126 for wid=2 using h264 with ratio 35.4% ( 675KB to 239KB), sequence 4, client_options={'pts': 0, 'frame': 0, 'csc': 'YUV444P', 'type': 'IDR', 'quality': 99, 'speed': 85} 2016-11-23 14:44:06,979 send_delayed for wid 2, batch delay is 52ms, elapsed time is 52ms 2016-11-23 14:44:06,979 send_delayed_regions: bytes_cost=175872, bytes_threshold=649209, pixel_count=172800 2016-11-23 14:44:06,979 send_delayed_regions: merged=[R(164, 126, 480, 360)], merged_bytes_cost=173824, bytes_cost=175872, merged_pixel_count=172800, pixel_count=172800 2016-11-23 14:44:06,981 process_damage_region: wid=2, adding pixel data to encode queue ( 480x360 - auto), elapsed time: 54.8 ms, request time: 1.3 ms, frame delay=0ms 2016-11-23 14:44:06,981 send_delayed_regions: sent 1 regions using ['auto']
Also, expected - so it is switching eventually (both go on to use rgb eventually), which is good.
And, rolling the server back to r14350:
016-11-23 14:48:36,905 send_delayed for wid 1, batch delay is 19ms, elapsed time is 50ms 2016-11-23 14:48:36,905 send_delayed_regions: bytes_cost=158708, bytes_threshold=94610, pixel_count=157684 2016-11-23 14:48:36,905 get_best_encoding_video(..) temporarily switching to lossless mode for 157684 pixels: low pixel count 2016-11-23 14:48:36,905 send_delayed_regions: using full window update 499x316 with rgb24 2016-11-23 14:48:36,906 process_damage_region: wid=1, adding pixel data to encode queue ( 499x316 - rgb24), elapsed time: 51.2 ms, request time: 0.6 ms, frame delay=0ms 2016-11-23 14:48:36,906 make_data_packet: image=XShmImageWrapper(BGRX: 0, 0, 499, 316), damage data: (1, 0, 0, 499, 316, 'rgb24') 2016-11-23 14:48:36,906 rgb_encode reformatting because BGRX not in ['RGB', 'RGBX'] 2016-11-23 14:48:36,906 rgb_reformat: converting XShmImageWrapper(BGRX: 0, 0, 499, 316) from BGRX to RGB using PIL 2016-11-23 14:48:36,907 rgb_reformat(XShmImageWrapper(RGB: 0, 0, 499, 316), ['RGB', 'RGBX'], False) converted from BGRX (630736 bytes) to RGB (473052 bytes) in 1.3ms, rowstride=1497 2016-11-23 14:48:36,908 rgb_encode using level=1, lz4 compressed 499x316 in rgb24/RGB: 473052 bytes down to 6217 2016-11-23 14:48:36,908 compress: 1.6ms for 499x316 pixels at 0,0 for wid=1 using rgb24 with ratio 1.0% ( 615KB to 6KB), sequence 1, client_options={'lz4': 1, 'rgb_format': 'RGB'} 2
Is what I get upon connecting an html5 client - there we go, that was a clear indicator of the issue we were seeing, so the changes in r14355 is what did it.
Closing.
this ticket has been moved to: https://github.com/Xpra-org/xpra/issues/1300