----- Original Message ----- > [drop_stats]id=0 #in-frames=99 #late=99 (100.00%, avg 2995.89 ms) > #drop-on-playback=0 (0.00%) > [drop_stats]id=0 #in-frames=198 #late=198 (100.00%, avg 2160.48 ms) > #drop-on-playback=3 (1.52%) > [drop_stats]id=0 #in-frames=297 #late=297 (100.00%, avg 1881.11 ms) > #drop-on-playback=12 (4.04%) > > But then: > > Why 5? How much I want to put a tweak there and see what happens if I change > that value. > > #define STREAM_PLAYBACK_SYNC_DROP_SEQ_LEN_LIMIT 5 > > Why 100? What happens if you change it? > > op->multi_media_time = mmtime + 100; /* workaround... */ > I don't get your tweaks, they look specific to the problem at hand, I don't think such esoteric code should be checked in code, it will just decay. > > Here is a more serious follow up with another tweaks I just pushed, > latency_offset: > > ddd@ptitpuce[traces] spice-gtk> spicy -t latency_offset=1900:drop_stats=25 -h > turbo -p 5901 > [drop_stats]id=0 #in-frames=25 #late=0 (0.00%, avg 0.00 ms) > #drop-on-playback=0 (0.00%) > […] > [drop_stats]id=0 #in-frames=225 #late=0 (0.00%, avg 0.00 ms) > #drop-on-playback=14 (6.22%) > [drop_stats]id=0 #in-frames=250 #late=17 (6.80%, avg 2027.82 ms) > #drop-on-playback=15 (6.00%) > [drop_stats]id=0 #in-frames=275 #late=36 (13.09%, avg 2353.86 ms) > #drop-on-playback=26 (9.45%) > [drop_stats]id=0 #in-frames=300 #late=58 (19.33%, avg 2445.26 ms) > #drop-on-playback=50 (16.67%) > [drop_stats]id=0 #in-frames=325 #late=58 (17.85%, avg 2445.26 ms) > #drop-on-playback=50 (15.38%) > same idea, this is playing with the code, not code that should remain. > > > >> > >> 3. What is actually received during the early protocol exchange? That’s > >> mostly for my curiosity, to see how chatty the protocol is, the size of > >> packets it tends to exchange, etc. To answer a question from Marc André, > >> this one and the next are tools that would immediately have shown me where > >> the macOS version was goofing up. > >> > >>> spicy -t wire_read -h turbo -p 5901 > >> [wire_read]Read 16 bytes in 0x7f8b150d85a8 > >> [wire_read]00000000: 52 45 44 51 02 00 00 00 02 00 00 00 BA 00 00 00 > >> > >> [wire_read]Read 186 bytes in 0x7f8b141c6650 > >> [wire_read]00000000: 00 00 00 00 30 81 9F 30 0D 06 09 2A 86 48 86 F7 > >> [wire_read]00000010: 0D 01 01 01 05 00 03 81 8D 00 30 81 89 02 81 81 > >> [wire_read]00000020: 00 D2 A9 FE 7B F0 36 B7 33 3C C1 F0 5E 10 50 F3 > >> [wire_read]00000030: 11 D3 3E 31 4A 95 AC AC 7B 0C 20 CB 57 B2 C8 1D > >> [wire_read]00000040: 10 F1 E2 4A 1A F2 8F 2A 03 70 25 BB 63 C7 D6 51 > >> [wire_read]00000050: D4 DA 64 3C 95 0C B6 9E A7 4E B3 3F 65 12 83 86 > >> [wire_read]00000060: F4 35 F3 AC 3D C3 9A 6C C9 EE 34 D9 67 F0 8A 2D > >> [wire_read]00000070: 53 4D 73 46 06 CA 80 04 CF 7F 72 4A 8D 74 81 78 > >> [wire_read]00000080: E8 28 39 51 7C 9E 3B C2 19 D6 BD EC B4 F7 0A 68 > >> [wire_read]00000090: D3 AF D7 1F E6 93 E1 4C 23 F5 83 68 E1 7D 31 9A > >> [wire_read]000000A0: 53 02 03 01 00 01 01 00 00 00 01 00 00 00 B2 00 > >> [wire_read]000000B0: 00 00 0B 00 00 00 09 00 00 00 > >> [wire_read]Read 4 bytes in 0x109478b44 > >> [wire_read]00000000: 00 00 00 00 > >> ** Message: main channel: opened > >> [wire_read]Read 6 bytes in 0x7f8b1274efb0 > >> [wire_read]00000000: 67 00 20 00 00 00 > >> [wire_read]Read 32 bytes in 0x7f8b1274dff0 > >> [wire_read]00000000: 31 AE 1E 5E 01 00 00 00 03 00 00 00 02 00 00 00 > >> [wire_read]00000010: 01 00 00 00 0A 00 00 00 9B AF BE 0B 00 00 00 01 > >> > > > > This is so low-level than even debug log don't make much sense. Imho when > > you need to read the byte-stream, you can just attach gdb and put a > > breakpoint/command. Then GDB allows to do a lot more interesting stuff, > > like conditional breakpoint, various print etc.. > > Valid opinion. Don’t like trace options, don’t have to use them. By why > prevent me from using them? Cluttering the code because you can't use proper tools is not acceptable imho. > > Please send me your GDB script for -t wire_read:marshall_read, which I use > for LEB128 development, and for -t drop_stats=25:latency_offset=N, which I > use to investigate where the latency is coming from. Please make it > compatible with LLDB too, unless you know how to install GDB on macOS (read > this first if you think I’m being silly > https://stackoverflow.com/questions/33162757/how-to-install-gdb-debugger-in-mac-osx-el-capitan). Well that looks like a general problem if you can't use debuggers on your platform. I don't own a mac to help you here, nor do I have much experience with it. > > > >> > >> 4. A symbolic view of the initial exchange (not all cases are covered in > >> marshal.py / demarshal.py yet, so some fields are likely missing). > >> > >>> spicy -t marshall_read -h turbo -p 5901 > >> > >> [marshall_read] SpiceMsgMainInit.session_id=1745897490 > >> [marshall_read] SpiceMsgMainInit.display_channels_hint=1 > >> [marshall_read] SpiceMsgMainInit.supported_mouse_modes=3 > >> [marshall_read] SpiceMsgMainInit.current_mouse_mode=2 > >> [marshall_read] SpiceMsgMainInit.agent_connected=1 > >> [marshall_read] SpiceMsgMainInit.agent_tokens=10 > >> [marshall_read] SpiceMsgMainInit.multi_media_time=226863047 > >> [marshall_read] SpiceMsgMainInit.ram_hint=16777216 > >> [marshall_read] SpiceMsgMainName.name_len=10 > >> [marshall_read] SpiceMsgPing.id=1 > >> [marshall_read] SpiceMsgPing.timestamp=226863447500 > >> [marshall_read] SpiceMsgPing.id=2 > >> [marshall_read] SpiceMsgPing.timestamp=226863447502 > >> [marshall_read] SpiceMsgPing.id=3 > >> [marshall_read] SpiceMsgPing.timestamp=226863447503 > >> [marshall_read] SpiceMsgChannels.num_of_channels=8 > >> [marshall_read] SpiceChannelId.type=2 > >> [marshall_read] SpiceChannelId.id=0 > >> [marshall_read] SpiceChannelId.type=4 > >> [marshall_read] SpiceChannelId.id=0 > >> [marshall_read] SpiceChannelId.type=9 > >> [marshall_read] SpiceChannelId.id=1 > >> [marshall_read] SpiceChannelId.type=9 > >> [marshall_read] SpiceChannelId.id=0 > >> [marshall_read] SpiceChannelId.type=6 > >> [marshall_read] SpiceChannelId.id=0 > >> [marshall_read] SpiceChannelId.type=5 > >> [marshall_read] SpiceChannelId.id=0 > >> [marshall_read] SpiceChannelId.type=2 > >> [marshall_read] SpiceChannelId.id=1 > >> [marshall_read] SpiceChannelId.type=3 > >> [marshall_read] SpiceChannelId.id=0 > > > > Same here, this is so verbose and low-level than you can simply attach gdb > > and pretty-print the structure you are interested in. > > Possible ≠ easy. You can also simply edit source code with sed. That does not > make it a good idea. > > > This is really just useful to developpers, no one else could make sense of > > these internal stuff. > > Asking a customer to send the output of spicy -t magic_trace seems easier > than asking them to run a gdb script. I never said you have to ask customer for running gdb. At this point, the developper should have enough information to reproduce the problem. I happened very seldomly that you have to provide the user with a custom binary for testing, which may provide additional log (a good indication that this log should be upstream this time) > > > > >> > >> I believe this example illustrates well the kind of instrumentation that > >> is > >> useful and convenient to have there all the time, but that we don’t want > >> to > >> send to a debug log if not explicitly requested. I see no reason to > >> pollute > >> even a structured log with that stuff, unless I actually need it. One line > >> per field with a common structure on purpose, to make it easy to grep / > >> awk > >> the data you want. > >> > > > > No, I don't think we need this available "all the time" or put differently, > > in the code. We need useful debug log, but when it comes to internal data > > structure dump or byte stream analaysis, use proper tools: gdb & > > tcpdump/wireshark for ex. > > Use what you want. But why prevent me from using tools I find less primitive > for the task? We don't have the same perception of primitive tools. > > > > I don't think you make a good point about the "log tweaks" either. > > I don’t see you having made any good point against them, only suggesting > purely theoretical alternatives that would turn minutes of work into days. You won't be surprised that I think quite the contrary. I'd simply like to: - not make needless tweaks available in production builds - not clutter the code with logging very specific to a bug (just imagine if everybody added its own bug-specific log in upstream code) - not reinvent the wheel (like parsing etc) - use existing logging infrastructure to be coherent with the rest of the system, and stay familiar to the developer/admin of that system - use existing, powerful tools and framework, familiar to existing developers What I consider useful in what you propose, is to add more debug and add log categories. The rest fits a poor-man way of debugging, imho, and doesn't match well with common practices and tools. I will study your patches in more details when I have time to see if I missed something. _______________________________________________ Spice-devel mailing list Spice-devel@xxxxxxxxxxxxxxxxxxxxx https://lists.freedesktop.org/mailman/listinfo/spice-devel