search

rockowitz / ddcutil

Control monitor settings using DDC/CI and USB
http://www.ddcutil.com
GNU General Public License v2.0
949 stars 39 forks source link

Problem using dynamic-sleep with Beng TT2200HD #325

Open digitaltrails opened 1 year ago

digitaltrails commented 1 year ago

In 2.0.0-dev dynamic sleep appears to be on by default. With a Beng TT2200HD, the capabilities operation mainly fails:

% ddcutil --enable-dynamic-sleep capabilities
(app_get_capabilities_string) !!! Unable to get capabilities for monitor on Display_Handle[i2c-3: fd=3 @0x55677fb40960]
(app_get_capabilities_string   ) Unexpected status code: DDCRC_ALL_RESPONSES_NULL(-3011): all tries returned DDC Null Message

I think sometimes eventually succeeds because I seen the error go away once, after which the capabilities are cached (not 100% sure how it went away). If I remove the cache the problem resurfaces.

On the other hand --disable-dynamic-sleep always works:

% ddcutil --disable-dynamic-sleep capabilities ## WORKS Model: T2200HD MCCS version: 2.0 Commands: Op Code: 01 (VCP Request) Op Code: 02 (VCP Response) ...

The problem seems to cause following getvcp/setvcp to fail. This seems to stop being a problem once capabilities are cached by running ddcutil --disable-dynamic-sleep capabilities.

I think this may be similar to the transient issue I was seeing with my HP ZR24.

Maybe the default for capabilities should be --disable-dynamic-sleep

The dsa file after the capabilities error run looks like:

FORMAT 2
* DEV  /dev/i2c device
* EC   EDID check sum byte
* C    current step
* I    interval remaining
* DEV EC C I Values
* Values {tries required, step, epoch seconds}
i2c-3 2a 1 3 10 {1,10,1688159364} {1,7,1688159364} {1,7,1688159364} {1,7,1688159364} {1,7,1688159366} {1,6,1688159366} {1,5,1688159366} {1,4,1688159366} {1,3,1688159366} {1,2,1688159366}

The dsa after things are settled is:

FORMAT 2
* DEV  /dev/i2c device
* EC   EDID check sum byte
* C    current step
* I    interval remaining
* DEV EC C I Values
* Values {tries required, step, epoch seconds}
i2c-3 2a 5 3 5 {2,5,1688158861} {2,5,1688158862} {2,5,1688158863} {2,5,1688158865} {2,5,1688158866} {2,5,1688158867} {2,5,1688158869} {2,5,1688158870} {2,5,1688158872} {2,5,1688158874} {2,5,1688158875} {2,5,1688158877} {2,5,1688158878} {2,5,1688158879} {2,5,1688158880} {2,5,1688158881} {2,5,1688158882} {2,5,1688158884} {2,5,1688158885} {2,5,1688158886}
digitaltrails commented 1 year ago

I did some more testing of just dragging the brightness slider in vdu_controls and was encountering quite a few failures, not absolute, but often, the cached dsa was:

* DEV  /dev/i2c device
* EC   EDID check sum byte
* C    current step
* I    interval remaining
* DEV EC C I Values
* Values {tries required, step, epoch seconds}
i2c-3 2a 3 3 5 {1,7,1688162253} {1,7,1688162267} {1,7,1688162267} {1,7,1688162269} {1,7,1688162269} {1,6,1688162269} {1,5,1688162269} {2,5,1688162276} {2,4,1688162277} {2,4,1688162279} {1,3,1688162286} {1,3,1688162294} {2,4,1688162296} {1,3,1688162298} {2,4,1688162299} {2,4,1688162301} {2,4,1688162302} {1,3,1688162309} {2,4,1688162314} {2,4,1688162316}

So I copied back the settled dsa file from the previous note:

FORMAT 2
* DEV  /dev/i2c device
* EC   EDID check sum byte
* C    current step
* I    interval remaining
* DEV EC C I Values
* Values {tries required, step, epoch seconds}
i2c-3 2a 5 3 5 {2,5,1688158861} {2,5,1688158862} {2,5,1688158863} {2,5,1688158865} {2,5,1688158866} {2,5,1688158867} {2,5,1688158869} {2,5,1688158870} {2,5,1688158872} {2,5,1688158874} {2,5,1688158875} {2,5,1688158877} {2,5,1688158878} {2,5,1688158879} {2,5,1688158880} {2,5,1688158881} {2,5,1688158882} {2,5,1688158884} {2,5,1688158885} {2,5,1688158886}

After switching to the above file, dragging the slider was totally error free.

Perhaps the dynamic adjustment is too optimistic for some old hardware. It works well for my newer LG. It seems OK for the HP ZR24w (but with the odd hiccup).

BTW, I was using a different (very old) machine for this test. I was using ddcutil 2.0.0-dev. Nvidia 470.182.03 driver (and older driver than my desktop machine) with a GTX 650Ti. DVI to DVI cable.

rockowitz commented 1 year ago

@digitaltrails It looks like the dynamic sleep algorithm is being insufficiently conservative. After pulling the latest changes to branch 2.0.0-dev, please try running the following script, which will loop until the capabilities command fails. (You'll likely have to edit the location of the ddcutil executable.)

#!/bin/sh

opts="--noconfig --tid   --ts --disable-capabilities-cache  --enable-dynamic-sleep  --trcfunc dsa2_too_many_errors --trcfunc dsa2_too_few_errors --trcfunc dsa2_adjust_for_recent_successes --trcfunc dsa2_record_final --trcfunc dsa2_get_adjusted_sleep_multiplier --trcfunc ddc_write_read_with_retry --trcfunc dsa2_note_retryable_failure --trcfunc dsa2_next_retry_step --istats all  "

ddcutil=src/ddcutil
echo "\$? = $?"
while true; do
   cat $HOME/.cache/ddcutil/dsa
   cmd="$ddcutil $opts  cap"
   echo $cmd
   $cmd
   [ $? -eq 0 ] || break
done
cat $HOME/.cache/ddcutil/dsa

The output from the last (failed) iteration of the loop is what I'm looking for.

In case the problem only occurs when running vdu_controls, I've added some options that will direct all trace output to the system log, but the output will be voluminous. Let's try this first.

Thanks.

digitaltrails commented 1 year ago

It does occur stand alone (without vdu_controls). Output attached. ddcutil-test-dyn-sleep.log

rockowitz commented 1 year ago

@digitaltrails The log you sent is perplexing. It shows all the ddc_write_read_with_retry() calls executing with sleep-multiplier from 1.0 to 2.0, yet all fail with a DDCRC_NULL_RESPONSE. It's as if I'm looking in the wrong place.

I've made some tweaks to the dsa2 algorithm and improved tracing. Please pull the latest 2.0.0-dev branch and execute the following updated script. Thanks.

#!/bin/sh

opts="--noconfig --tid   --ts --disable-capabilities-cache  --enable-dynamic-sleep  --trcfunc dsa2_too_many_errors --trcfunc dsa2_too_few_errors --trcfunc dsa2_adjust_for_rcnt_successes --trcfunc dsa2_record_final --trcfunc dsa2_get_adjusted_sleep_mult  --trcfunc dsa2_note_retryable_failure --trcfunc dsa2_next_retry_step --trcfunc ddc_initial_checks_by_dh  --trcfunc dsa2_note_retryable_failure --trcfunc dsa2_save_persistent_stats --trcfunc ddc_write_read_with_retry --istats all"

ddcutil=src/ddcutil                        # may have to change 
echo "\$? = $?"
while true; do
   cat $HOME/.cache/ddcutil/dsa
   cmd="$ddcutil $opts  cap --dis 1 $@"   # may have to change --display option for problematic monitor
   echo $cmd
   $cmd
   [ $? -eq 0 ] || break
done
cat $HOME/.cache/ddcutil/dsa
digitaltrails commented 1 year ago

Can the monitor or bus become overwhelmed. On at least one occasion it must have worked (because I have that dsa file with 2.0 in it). So I wonder if things are happening too fast for some aspect of the hardware/software. I've yet to find time to try the latest code - might have to be be tomorrow.

digitaltrails commented 1 year ago

@digitaltrails The log you sent is perplexing. It shows all the ddc_write_read_with_retry() calls executing with sleep-multiplier from 1.0 to 2.0, yet all fail with a DDCRC_NULL_RESPONSE. It's as if I'm looking in the wrong place.

I've made some tweaks to the dsa2 algorithm and improved tracing. Please pull the latest 2.0.0-dev branch and execute the following updated script. Thanks.

It seems to lockup - never exits. I ran it with strace, here is the tail end of the trace:

clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=100000000}, NULL) = 0
readlink("/proc/self/fd/3", "/dev/i2c-3", 4096) = 10
readlink("/proc/self/fd/3", "/dev/i2c-3", 4096) = 10
readlink("/proc/self/fd/3", "/dev/i2c-3", 4096) = 10
ioctl(3, _IOC(_IOC_NONE, 0x7, 0x7, 0), 0x7ffcc8316210) = 1
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=100000000}, NULL) = 0
readlink("/proc/self/fd/3", "/dev/i2c-3", 4096) = 10
readlink("/proc/self/fd/3", "/dev/i2c-3", 4096) = 10
ioctl(3, _IOC(_IOC_NONE, 0x7, 0x7, 0), 0x7ffcc83161e0) = 1
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=520, tv_nsec=105296000},```

ddcutil-test-2023-07-05.log

rockowitz commented 1 year ago

That doesn't help me much. What happens if you run with --trace all? The output will be voluminous, but should give a better idea of where the lockup occurs.

digitaltrails commented 1 year ago

I ran ddcutil --trace all detect, the output reveals rather a large sleep:

...
(invoke_i2c_writer             )           strategy = I2C_IO_STRATEGY_IOCTL
(i2c_ioctl_writer              ) Starting  fh=3, filename=/dev/i2c-3, slave_address=0x37, bytect=5, pbytes=0x557ea21452f1 -> 51 82 01 df 63
   i2c_rdwr_ioctl_data at: 0x7ffebb5ca4a0
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0000
         len:     0x0005 (5)
         buf:     0x557ea21452f1 ->  51 82 01 df 63
(i2c_ioctl_writer              ) Done      Returning: OK(0). 
(invoke_i2c_writer             ) Done      Returning: OK(0). 
(tuned_sleep_with_trace        ) Starting  dh=Display_Handle[i2c-3: fd=3 @0x557ea2141490], sleep event type=SE_WRITE_TO_READ, special_sleep_time_millis=0
(tuned_sleep_with_trace        )           Called from func=ddc_i2c_write_read_raw, filename=ddc_packet_io.c, lineno=451, msg=|(null)|
(get_sleep_time                ) Starting  Sleep event type = SE_WRITE_TO_READ, special_sleep_time_millis=0
(get_sleep_time                ) Done      Returning: 50, *is_deferrable_loc = false
(adjust_sleep_time             ) Starting  dh=Display_Handle[i2c-3: fd=3 @0x557ea2141490], spec_sleep_time_millis=50
(adjust_sleep_time             ) Done      spec_sleep_time_millis = 50, dsa_multiplier=10661921.00, Returning: 533096050
(sleep_millis_with_trace       )           Sleeping for 533096050 milliseconds. Event_type: SE_WRITE_TO_READ

trace-all-2023-07-06.log

digitaltrails commented 1 year ago

I don't know if it's significant, but on my normal desktop, when I woke up the monitors from suspend, this was running via vdu_controls (which retried successfully):

Journal Entry 2023-07-06 17:53:27.582445+12:00

MESSAGE                  : (dsa2_restore_persistent_stats) busno=0, resetting invalid cur_step from 11 to 10
PRIORITY                 : 3
SYSLOG_FACILITY          : 1
SYSLOG_IDENTIFIER        : ddcutil
SYSLOG_PID               : 3935
SYSLOG_TIMESTAMP         : Jul  6 17:53:27 
_AUDIT_LOGINUID          : 500
_AUDIT_SESSION           : 4
_BOOT_ID                 : 67e8da11-798b-425c-9dc1-5d4970df2f9f
_CAP_EFFECTIVE           : 0
_CMDLINE                 : ddcutil --enable-dynamic-sleep --force --brief getvcp 10 --edid 00ffffffffffff0022f069280101010108140104a53623782efc81a4554d9d25125054210800814081809500a940b300d1c001010101283c80a070b023403020360022602100001a000000fd003b3d185011000a202020202020000000fc004850205a523234770a20202020000000ff00434e5430303831314a360a2020003d
_COMM                    : ddcutil
_EXE                     : /home/michael/bin/ddcutil
rockowitz commented 1 year ago

The large sleep and the syslog message reflect the same problem. If the index into the steps array is beyond the end, the sleep multiplier used is whatever happens to be in memory, causing in your case the long sleep. There's a sanity check on the current step when restoring stats, which caused the syslog report.

I have reworked the functions that adjust the sleep-multiplier step based on recent successes and failures and in the process removed a cause of the above error. I have also tweaked the retryability of the DDC Null Response, which is ambiguous as an indication of whether an operation can be retried. The changes have been pushed to branch 2.0.0-dev.

I've also slightly modified the script to count the number of times through the loop. If you need to specify a display number or other display selector, the option can go on the script command line.

I've run the script against the 3 displays on this workstation (RX 580, amdgpu). Each ran until the display disappeared because it powered off: 3760 times for a HDMI connection, 1491 times for a DVI connection, and 4940 times for a DP connected monitor. Over the weekend I should have a chance to install a Nvidia card on a test system and run the script there.

#!/bin/sh

opts="--noconfig --tid   --ts --disable-capabilities-cache  --enable-dynamic-sleep  --trcfunc dsa2_too_many_errors --trcfunc dsa2_too_few_errors --trcfunc dsa2_adjust_for_rcnt_successes --trcfunc dsa2_record_final --trcfunc dsa2_get_adjusted_sleep_mult  --trcfunc dsa2_note_retryable_failure --trcfunc dsa2_next_retry_step --trcfunc ddc_initial_checks_by_dh  --trcfunc dsa2_note_retryable_failure --trcfunc dsa2_save_persistent_stats --trcfunc ddc_write_read_with_retry --istats all"

ddcutil=src/ddcutil                        # may have to change 
loopctr=0
while true; do
   loopctr=$((loopctr+1))
   printf "\n=====> Starting loop %d\n" $loopctr
   cat $HOME/.cache/ddcutil/dsa
   # cmd="$ddcutil detect"
   # echo $cmd
   # $cmd
   # [ $? -eq 0 ] || break
   cmd="$ddcutil $opts  cap  $@"  
   echo $cmd
   $cmd
   [ $? -eq 0 ] || break
done
printf "======> ddcutil command failed on loop %d\n" $loopctr
cat $HOME/.cache/ddcutil/dsa
digitaltrails commented 1 year ago

Some progress (but not all good):

# rm -rf .cache/ddcutil; bin/ddcutil --enable-dynamic-sleep detect 
(lock_display                  ) Starting  id=0x5576f786d5d0 -> Display_Lock_Record[Display_Path[/dev/i2c-3] @0x5576f786d5d0]
(lock_display                  ) Done      Returning: NULL. id=0x5576f786d5d0 -> Display_Lock_Record[Display_Path[/dev/i2c-3] @0x5576f786d5d0]
(unlock_display                ) Starting  id=0x5576f786d5d0 -> Display_Lock_Record[Display_Path[/dev/i2c-3] @0x5576f786d5d0]
(unlock_display                ) Done      Returning: NULL. id=0x5576f786d5d0 -> Display_Lock_Record[Display_Path[/dev/i2c-3] @0x5576f786d5d0]
Display 1
   I2C bus:  /dev/i2c-3
   DRM connector:           card0-DVI-D-1
   EDID synopsis:
      Mfg id:               BNQ - UNK
      Model:                BenQ T2200HD
      Product code:         30502  (0x7726)
      Serial number:        2C803527SL0
      Binary serial number: 21573 (0x00005445)
      Manufacture year:     2008,  Week: 51
   VCP version:         2.0

But capabilities fails with --enable-dynamic-sleep (but works if it is disabled):

% rm -rf .cache/ddcutil; bin/ddcutil --enable-dynamic-sleep capabilities 
(lock_display                  ) Starting  id=0x555a74e835d0 -> Display_Lock_Record[Display_Path[/dev/i2c-3] @0x555a74e835d0]
(lock_display                  ) Done      Returning: NULL. id=0x555a74e835d0 -> Display_Lock_Record[Display_Path[/dev/i2c-3] @0x555a74e835d0]
(unlock_display                ) Starting  id=0x555a74e835d0 -> Display_Lock_Record[Display_Path[/dev/i2c-3] @0x555a74e835d0]
(unlock_display                ) Done      Returning: NULL. id=0x555a74e835d0 -> Display_Lock_Record[Display_Path[/dev/i2c-3] @0x555a74e835d0]
(lock_display                  ) Starting  id=0x555a74e835d0 -> Display_Lock_Record[Display_Path[/dev/i2c-3] @0x555a74e835d0]
(lock_display                  ) Done      Returning: NULL. id=0x555a74e835d0 -> Display_Lock_Record[Display_Path[/dev/i2c-3] @0x555a74e835d0]
(app_get_capabilities_string) !!! Unable to get capabilities for monitor on Display_Handle[i2c-3: fd=3 @0x555a74e5c530]
(app_get_capabilities_string   ) Unexpected status code: DDCRC_ALL_RESPONSES_NULL(-3011): all tries returned DDC Null Message
(unlock_display                ) Starting  id=0x555a74e835d0 -> Display_Lock_Record[Display_Path[/dev/i2c-3] @0x555a74e835d0]
(unlock_display                ) Done      Returning: NULL. id=0x555a74e835d0 -> Display_Lock_Record[Display_Path[/dev/i2c-3] @0x555a74e835d0]

The loop script fails on loop 1. ddcutil-test-dyn-sleep-2023-07-08.log

On my newer system with the LG+HP VDU's the loop script keeps looping, so it's just this old Beng and an old NVidia card.

rockowitz commented 1 year ago

By any chance are you using an explicit --sleep-multiplier value greater than 2.0 for this monitor?

digitaltrails commented 1 year ago

By any chance are you using an explicit --sleep-multiplier value greater than 2.0 for this monitor?

Definitely not in the manual tests I ran above. The command line is included at the top of each quoted output.

rockowitz commented 1 year ago

@digitaltrails Please ignore the last comment I just deleted. I'm having a hard time coming with a reason why the monitor keeps returning the DDC Null Message when all that dynamic sleep is doing is varying the sleep time, whereas with dynamic sleep off there's just a single fixed sleep time.

digitaltrails commented 1 year ago

My suspicion is that i2c to the Beng or Nvidia-card is being driven too fast and getting swamped to the point that it behaves differently. I experimentally altered src/base/sleep.c to add some milliseconds, starting at 10 and doubling, I found that at += 80 the command rm -rf .cache/ddcutil; ddcutil capabilities works.

void sleep_millis_with_trace(
        int          milliseconds,
        const char * func,
        int          lineno,
        const char * filename,
        const char * message)
{
   bool debug = false;

   if (!message)
      message = "";

   milliseconds += 80;  /* experimenting with being a bit more conservative */

   DBGTRC_NOPREFIX(debug, DDCA_TRC_SLEEP,
                   "Sleeping for %d milliseconds. %s", milliseconds, message);

   if (milliseconds > 0)
      sleep_millis(milliseconds);
}

Perhaps what sleep multiplier will work may change if the driver/firmware/hardware is overwhelmed. The capabilities command seems a bit exceptional - perhaps it's more sensitive or prone to such glitches. A lot of hand waving and guessing on my part.

If a dsa based operation fails, could ddcutil fall back to the standard sleep multiplier?

digitaltrails commented 1 year ago

More info: I just tried ddcutil 1.4.1 with the Beng and capabilities it failed until I set a sleep multiplier of 1.1:

% /usr/bin/ddcutil --version                                                                                                                          
ddcutil 1.4.1
...
% rm -rf ~/.cache/ddcutil ; /usr/bin/ddcutil --sleep-multiplier=1.1 capabilities
(lock_display                  ) Starting  id=0x55efac89c780 -> Display_Lock_Record[Display_Path[/dev/i2c-3] @0x55efac89c780]
(lock_display                  ) Done      Returning: NULL. id=0x55efac89c780 -> Display_Lock_Record[Display_Path[/dev/i2c-3] @0x55efac89c780]
(unlock_display                ) Starting  id=0x55efac89c780 -> Display_Lock_Record[Display_Path[/dev/i2c-3] @0x55efac89c780]
(unlock_display                ) Done      Returning: NULL. id=0x55efac89c780 -> Display_Lock_Record[Display_Path[/dev/i2c-3] @0x55efac89c780]
(lock_display                  ) Starting  id=0x55efac89c780 -> Display_Lock_Record[Display_Path[/dev/i2c-3] @0x55efac89c780]
(lock_display                  ) Done      Returning: NULL. id=0x55efac89c780 -> Display_Lock_Record[Display_Path[/dev/i2c-3] @0x55efac89c780]
Model: T2200HD
MCCS version: 2.0
Commands:
   Op Code: 01 (VCP Request)
...

This is also true for 2.0.0-dev with --disable-dynamic-sleep. So the Beng is certainly a bit sluggish. Other commands such as detect, getvcp, and setvcp seem to work fine with a multiplier of 1.0 (possibly caching was hiding the difference in some past tests).

Edit: I was testing remotely, I just found a multiplier of 1.0 is fine as long as the screen isn't in power saving (but the power saving sate doesn't make any difference to `--enable-dynamic-sleep).

rockowitz commented 1 year ago

Your conjecture that the Nvidia card/Benq monitor combination is being driven too hard makes sense. The question is which is the culprit - that would take sniffing the line. The DDC Null Message is a bit of a catch-all. The relevant use here is "To tell the host that the display does not have any answer to give to the host (not ready or not expected)." Unfortunately that covers both a problem in the monitor (which could be request for a reply packet that comes in too soon or some other problem in the monitor's DDC/CI implementation), and the monitor having received a malformed request from the host. To make things even more ambiguous, some monitors use the Null Message to indicate an unsupported feature instead of setting a bit in a getvcp reply packet.

As I've noted elsewhere, reading the capabilities string is by far the most complex, error prone, and expensive DDC/CI operation, (setting aside reading and writing features of type Table, which is a generalization of reading the capabilities string and is rare). It requires multiple write request/read response cycles, since a single response can return at most 32 bytes.

Further conjecture. With dynamic sleep enabled, the initial requests with very short sleep time put the card/monitor into a problematic state from which they do not recover even as dynamic sleep increases the sleep multiplier to 2. Perhaps multi-part read requests (i.e. capabilities requests) should ignore dynamic sleep, or perhaps there should be special handling for the case where write/read requests consistently return the Null Message.

digitaltrails commented 1 year ago

I can try the Beng on my main desktop. It also has a Nvidia card, but a more recent one and uses the 500 series driver instead of the 400 series. The next couple of days are a bit hectic, but Thursday NZ time at the latest.

The capabilities command takes so long, having it take a bit longer seems like an OK compromise.

The monitor does recover and respond to later commands. The time taken by me do a command recall in bash and pressing enter is roughly enough. Perhaps as a last resort you could delay a while and then try with a long sleep interval.

Instead of staring short and going longer, would starting long and going shorter, be more stable? I suppose the monitor is exchange is still eventually going to trip the problem.

digitaltrails commented 1 year ago

I tried the Beng on my main desktop PC. It was connected DVI-HDMI, I'm using the Nvidia 525.116.04 driver. I had to use a sleep-multiplier of 1.1 to be able to get it to respond to the capabilities command:

rm -rf ~/.cache/ddcutil; ddcutil --disable-dynamic-sleep --sleep-multiplier 1.1 --display 2 capabilities

It seemed to always fail with a multiplier of 1.0, almost always succeed on 1.1, and I haven't seen 1.2 fail (in a about 6 tries).

Both getvcp and setvcp work fine with dynamic-sleep enabled.

Perhaps this monitor is too old and slow.

rockowitz commented 1 year ago

@digitaltrails Based on your tests, I have modified multi_part_read_with_retry() to sleep for an optional amount of time after try_multi_part_read() indicates that all its calls to ddc_write_read_with_retry() received a NULL message response. Hopefully you can find a sleep duration that causes the video card or monitor to reset, if that is the problem. Temporary use option --i2 specifies the sleep time in milliseconds. add multi_part_read_with_retry to the list of traced functions. If the additional sleep occurs, a trace message is issued unconditionally.

Re:

Instead of staring short and going longer, would starting long and going shorter, be more stable?

We've seen that even when the cache file sets the initial multiplier to 2.0 the error occurs. And starting long on every ddcutil defeats the dynamic sleep adjustment, since it takes many ddcutil invocations to have enough data to adjust the sleep time downwards.

The original dynamic sleep algorithm added a 100 ms sleep in the retry loop of ddc_write_read_with_retry() in case of a DDC Null Message. Based on what you find I may try adding similar code to the the current dynamic sleep algorithm.

rockowitz commented 1 year ago

@digitaltrails I have installed a Nvidia 660ti using driver 535.54 on a test system, and put my most ornery monitor, a Dell P2411h, on it. Lots of DDCRC_DDC_DATA errors, but no DDCRC_NULL_MESSAGE responses.

digitaltrails commented 1 year ago

The modified version works out of the box. There was no need to specify an --i2 value:

rm -rf ~/.cache/ddcutil ; ./bin/ddcutil  --enable-dynamic-sleep capabilities
Model: T2200HD
MCCS version: 2.0
Commands:
   Op Code: 01 (VCP Request)
   Op Code: 02 (VCP Response)
   Op Code: 03 (VCP Set)
   Op Code: 07 (Timing Request)
   Op Code: 0C (Save Settings)
   Op Code: E3 (Capabilities Reply)
   Op Code: F3 (Capabilities Request)
VCP Features:
   Feature: 02 (New control value)
   Feature: 04 (Restore factory defaults)
   Feature: 05 (Restore factory brightness/contrast defaults)
   Feature: 08 (Restore color defaults)
   Feature: 10 (Brightness)
   Feature: 12 (Contrast)
   Feature: 14 (Select color preset)
      Values:
         05: 6500 K
         06: 7500 K
         08: 9300 K
         0b: User 1
   Feature: 16 (Video gain: Red)
   Feature: 18 (Video gain: Green)
   Feature: 1A (Video gain: Blue)
   Feature: 3E (Clock phase)
   Feature: 52 (Active control)
   Feature: 60 (Input Source)
      Values:
         01: VGA-1
         03: DVI-1
   Feature: 6C (Video black level: Red)
   Feature: 6E (Video black level: Green)
   Feature: 70 (Video black level: Blue)
   Feature: AC (Horizontal frequency)
   Feature: AE (Vertical frequency)
   Feature: B2 (Flat panel sub-pixel layout)
   Feature: B6 (Display technology type)
   Feature: C0 (Display usage time)
   Feature: C8 (Display controller type)
   Feature: C9 (Display firmware level)
   Feature: CC (OSD Language)
      Values:
         01: Chinese (traditional, Hantai)
         02: English
         03: French
         04: German
         05: Italian
         06: Japanese
         09: Russian
         0a: Spanish
   Feature: D6 (Power mode)
      Values:
         01: DPM: On,  DPMS: Off
         05: Write only value to turn off display
   Feature: DF (VCP Version)

Because I had replugged cables, I ran both a previous dev pull and the new one. The previous pull still fails, and the latest pull works. It's a bit slow on getting capabilities, which isn't an issue as far as I'm concerned. It hasn't failed in 10 or so attempts so far. Yay!

digitaltrails commented 1 year ago

With --trcfunc:

(multi_part_read_with_retry    ) Starting  request_type=0xf3, request_subtype=0x00, all_zero_response_ok=false, max_multi_part_read_tries=8
(multi_part_read_with_retry    )           Start of while loop. try_ctr=0, max_multi_part_read_tries=8
(multi_part_read_with_retry    )           After try loop. tryctr=1, rc=0. ddc_excp=NULL
(multi_part_read_with_retry    ) Done      Returning: NULL. *buffer_loc = 0x5646d6783d10
   Buffer at 0x5646d6783d10, bytes addr=0x5646d67abb20, len=235, max_size=2048
           +0          +4          +8          +c            0   4   8   c   
   +0000   28 70 72 6f 74 28 6d 6f 6e 69 74 6f 72 29 74 79   (prot(monitor)ty
   +0010   70 65 28 4c 43 44 29 6d 6f 64 65 6c 28 54 32 32   pe(LCD)model(T22
   +0020   30 30 48 44 29 63 6d 64 73 28 30 31 20 30 32 20   00HD)cmds(01 02 
   +0030   30 33 20 30 37 20 30 43 20 45 33 20 46 33 29 76   03 07 0C E3 F3)v
   +0040   63 70 28 30 32 20 30 34 20 30 35 20 30 38 20 31   cp(02 04 05 08 1
   +0050   30 20 31 32 20 31 34 28 30 35 20 30 36 20 30 38   0 12 14(05 06 08
   +0060   20 30 42 29 20 31 36 20 31 38 20 31 41 20 33 45    0B) 16 18 1A 3E
   +0070   20 35 32 20 36 30 28 30 31 20 30 33 29 20 36 43    52 60(01 03) 6C
   +0080   20 36 45 20 37 30 20 41 43 20 41 45 20 42 32 20    6E 70 AC AE B2 
   +0090   42 36 20 43 30 20 43 38 20 43 39 20 20 43 43 28   B6 C0 C8 C9  CC(
   +00a0   30 31 20 30 32 20 30 33 20 30 34 20 30 35 20 30   01 02 03 04 05 0
   +00b0   36 20 30 39 20 30 41 29 20 44 36 28 30 31 20 30   6 09 0A) D6(01 0
   +00c0   35 29 20 44 46 29 6d 73 77 68 71 6c 28 31 29 61   5) DF)mswhql(1)a
   +00d0   73 73 65 74 5f 65 65 70 28 34 30 29 6d 63 63 73   sset_eep(40)mccs
   +00e0   5f 76 65 72 28 32 2e 30 29 29 00                  _ver(2.0)).     
Model: T2200HD
MCCS version: 2.0
Commands:
   Op Code: 01 (VCP Request)

   ...

   Feature: DF (VCP Version)
./bin/ddcutil --trcfunc multi_part_read_with_retry capabilities  0.02s user 0.42s system 3% cpu 12.209 total

Seems to always report tryctr=1 - which looking at the code seems to imply only 1 iteration.

The elapsed time is around 12.2 seconds, which does vary much, even with different --i2 values.

digitaltrails commented 1 year ago

I tried the new version with the Beng connected to my normal desktop. The capabilities command most often works, but sometimes errors (perhaps 1 in 5). Typically:

+ ddcutil --trcfunc multi_part_read_with_retry --display 2 capabilities
(multi_part_read_with_retry    ) Starting  request_type=0xf3, request_subtype=0x00, all_zero_response_ok=false, max_multi_part_read_tries=8
(multi_part_read_with_retry    )           Start of while loop. try_ctr=0, max_multi_part_read_tries=8
(multi_part_read_with_retry    )           Terminating loop for DDCRC_ALL_RESPONSES_NULL
(multi_part_read_with_retry    )           After try loop. tryctr=1, rc=-3011. ddc_excp=Error_Info[DDCRC_ALL_RESPONSES_NULL in ddc_write_read_with_retry, causes: DDCRC_DDC_DATA(2), DDCRC_NULL_RESPONSE]
(multi_part_read_with_retry    ) Done      Returning: Error_Info[DDCRC_ALL_RESPONSES_NULL in multi_part_read_with_retry, causes: DDCRC_ALL_RESPONSES_NULL]. *buffer_loc = (nil)
(app_get_capabilities_string) !!! Unable to get capabilities for monitor on Display_Handle[i2c-1: fd=3 @0x55fe2155f4a0]
(app_get_capabilities_string   ) Unexpected status code: DDCRC_ALL_RESPONSES_NULL(-3011): all tries returned DDC Null Message
rockowitz commented 1 year ago

Re the first log, tryctr is 1 because on the first iteration of the loop the call to try_multi_part_read() returned NULL, i.e. it succeeded. --i2 only applies when multi_part_read() returns ErrorInfo[DDC_ALL_RESPONSES_NULL] or ErrorInfo[DDC_NULL_RESPONSE].

However ...

Re the second log. Recall that some ill-behaved monitors use the DDC Null Message to indicate that a feature is not supported instead of setting the unsupported bit in a normal reply packet. As part of initialization, ddcutil tries to figure out if that is the case. So before applying the --i2 sleep value and retrying, multi_part_read_with_retry() checks to see if the Null Message indicates an unsupported feature and if so returns immediately. The initialization code got it wrong about how unsupported features are indicated. Why does multi_part_read_with_retry() even care about an unsupported feature when it is reading capabilities? The same code is used for reading Table type features, for which the only way to indicate an unsupported feature is the Null Message.

Bottom line is that the edge cases need better handling, particularly the check for how an unsupported feature is reported.

But see the next comment...

rockowitz commented 1 year ago

The latest set of changes implement an earlier mechanism for recovering from Null Message errors in ddc_write_read_with_retry(), which is (ultimately) called in multi_part_read_with_retry()'s loop. Utility option --f7 enables it. If the mechanism kicks in a trace message is written to the terminal unconditionally (and written to the system log).

The test script has been tweaked again: 

#!/bin/sh

# trcopts="--trcfunc dsa2_too_many_errors --trcfunc dsa2_too_few_errors --trcfunc dsa2_adjust_for_rcnt_successes --trcfunc dsa2_record_final --trcfunc dsa2_get_adjusted_sleep_mult  --trcfunc dsa2_note_retryable_failure --trcfunc dsa2_next_retry_step --trcfunc ddc_initial_checks_by_dh  --trcfunc dsa2_note_retryable_failure --trcfunc dsa2_save_persistent_stats --trcfunc ddc_write_read_with_retry --trcfunc multi_part_read_with_retry --trcfunc adjust_sleep_time"
opts="--noconfig --tid --ts $trcopts --disable-capabilities-cache --enable-dynamic-sleep"

rm  $HOME/.cache/ddcutil/dsa
ddcutil=src/ddcutil                        # may have to change 
loopctr=0
while true; do
   loopctr=$((loopctr+1))
   printf "\n=====> Starting loop %d\n" $loopctr
   cat $HOME/.cache/ddcutil/dsa
   # cmd="$ddcutil detect"
   # echo $cmd
   # $cmd
   # [ $? -eq 0 ] || break
   cmd="$ddcutil $opts  cap  $@"   # if necessary, specify --display option here or on command line
   echo ""
   echo $cmd
   $cmd
   [ $? -eq 0 ] || break
done
printf "======> ddcutil command failed on loop %d\n" $loopctr
cat $HOME/.cache/ddcutil/dsa

I look forward to learning what you find.

digitaltrails commented 1 year ago

Looking good. It's currently reached 41 iterations. I've left it running.

The script isn't passing --f7 - is that correct?

Some of my past looping tests on my main desktop will have been tripped up by vdu_controls, it was idle in the system tray, but would have been periodically checking ambient lux versus VDU brightness. I made sure it was off this time. This would only apply to my main desktop, not my older test machine. So perhaps failing every 5 or so tries was due to contention. Sorry about any confusion this may have caused.

=====> Starting loop 1
cat: /home/michael/.cache/ddcutil/dsa: No such file or directory

/home/michael/bin/ddcutil --display 2 --noconfig --tid --ts --disable-capabilities-cache --enable-dynamic-sleep cap
Model: T2200HD
MCCS version: 2.0
Commands:
   Op Code: 01 (VCP Request)
   Op Code: 02 (VCP Response)
   Op Code: 03 (VCP Set)
   Op Code: 07 (Timing Request)
   Op Code: 0C (Save Settings)
   Op Code: E3 (Capabilities Reply)
   Op Code: F3 (Capabilities Request)
VCP Features:
   Feature: 02 (New control value)
   Feature: 04 (Restore factory defaults)
   Feature: 05 (Restore factory brightness/contrast defaults)
   Feature: 08 (Restore color defaults)
   Feature: 10 (Brightness)
   Feature: 12 (Contrast)
   Feature: 14 (Select color preset)
      Values:
         05: 6500 K
         06: 7500 K
         08: 9300 K
         0b: User 1
   Feature: 16 (Video gain: Red)
   Feature: 18 (Video gain: Green)
   Feature: 1A (Video gain: Blue)
   Feature: 3E (Clock phase)
   Feature: 52 (Active control)
   Feature: 60 (Input Source)
      Values:
         01: VGA-1
         03: DVI-1
   Feature: 6C (Video black level: Red)
   Feature: 6E (Video black level: Green)
   Feature: 70 (Video black level: Blue)
   Feature: AC (Horizontal frequency)
   Feature: AE (Vertical frequency)
   Feature: B2 (Flat panel sub-pixel layout)
   Feature: B6 (Display technology type)
   Feature: C0 (Display usage time)
   Feature: C8 (Display controller type)
   Feature: C9 (Display firmware level)
   Feature: CC (OSD Language)
      Values:
         01: Chinese (traditional, Hantai)
         02: English
         03: French
         04: German
         05: Italian
         06: Japanese
         09: Russian
         0a: Spanish
   Feature: D6 (Power mode)
      Values:
         01: DPM: On,  DPMS: Off
         05: Write only value to turn off display
   Feature: DF (VCP Version)

=====> Starting loop 2
FORMAT 2
* DEV  /dev/i2c device
* EC   EDID check sum byte
* C    current step
* I    interval remaining
* L    current lookback
* DEV EC C I L Values
* Values {tries required, step, epoch seconds}
i2c-0 3d 7 3 5 {1,7,1689307308} {1,7,1689307308}
i2c-1 2a 10 3 14 {1,7,1689307315} {1,6,1689307316} {1,5,1689307316} {1,4,1689307316} {1,3,1689307317} {1,2,1689307317} {1,1,1689307317} {1,0,1689307317} {1,0,1689307318} {1,0,1689307318} {1,0,1689307318} {1,0,1689307318} {1,0,1689307319} {1,0,1689307319} {1,0,1689307319} {1,0,1689307319} {1,0,1689307320} {1,0,1689307320} {1,0,1689307320} {1,0,1689307320}
i2c-3 9e 7 3 5 {1,7,1689307312} {1,7,1689307312}

/home/michael/bin/ddcutil --display 2 --noconfig --tid --ts --disable-capabilities-cache --enable-dynamic-sleep cap
Model: T2200HD
MCCS version: 2.0
Commands:
   Op Code: 01 (VCP Request)
   Op Code: 02 (VCP Response)
   Op Code: 03 (VCP Set)
   Op Code: 07 (Timing Request)
   Op Code: 0C (Save Settings)
   Op Code: E3 (Capabilities Reply)
   Op Code: F3 (Capabilities Request)
VCP Features:
   Feature: 02 (New control value)
   Feature: 04 (Restore factory defaults)
   Feature: 05 (Restore factory brightness/contrast defaults)
   Feature: 08 (Restore color defaults)
   Feature: 10 (Brightness)
   Feature: 12 (Contrast)
   Feature: 14 (Select color preset)
      Values:
         05: 6500 K
         06: 7500 K
         08: 9300 K
         0b: User 1
   Feature: 16 (Video gain: Red)
   Feature: 18 (Video gain: Green)
   Feature: 1A (Video gain: Blue)
   Feature: 3E (Clock phase)
   Feature: 52 (Active control)
   Feature: 60 (Input Source)
      Values:
         01: VGA-1
         03: DVI-1
   Feature: 6C (Video black level: Red)
   Feature: 6E (Video black level: Green)
   Feature: 70 (Video black level: Blue)
   Feature: AC (Horizontal frequency)
   Feature: AE (Vertical frequency)
   Feature: B2 (Flat panel sub-pixel layout)
   Feature: B6 (Display technology type)
   Feature: C0 (Display usage time)
   Feature: C8 (Display controller type)
   Feature: C9 (Display firmware level)
   Feature: CC (OSD Language)
      Values:
         01: Chinese (traditional, Hantai)
         02: English
         03: French
         04: German
         05: Italian
         06: Japanese
         09: Russian
         0a: Spanish
   Feature: D6 (Power mode)
      Values:
         01: DPM: On,  DPMS: Off
         05: Write only value to turn off display
   Feature: DF (VCP Version)

=====> Starting loop 3
FORMAT 2
* DEV  /dev/i2c device
* EC   EDID check sum byte
* C    current step
* I    interval remaining
* L    current lookback
* DEV EC C I L Values
* Values {tries required, step, epoch seconds}
i2c-0 3d 7 3 5 {1,7,1689307308} {1,7,1689307308} {1,7,1689307321} {1,7,1689307321}
i2c-1 2a 10 3 20 {1,3,1689307328} {1,2,1689307329} {1,1,1689307329} {1,0,1689307329} {1,0,1689307329} {1,0,1689307330} {1,0,1689307330} {1,0,1689307330} {1,0,1689307330} {1,0,1689307331} {1,0,1689307331} {1,0,1689307331} {1,0,1689307331} {1,0,1689307332} {1,0,1689307332} {1,0,1689307332} {1,0,1689307332} {1,0,1689307333} {1,0,1689307333} {1,0,1689307333}
i2c-3 9e 7 3 5 {1,7,1689307312} {1,7,1689307312} {1,7,1689307326} {1,7,1689307326}

/home/michael/bin/ddcutil --display 2 --noconfig --tid --ts --disable-capabilities-cache --enable-dynamic-sleep cap
Model: T2200HD
MCCS version: 2.0
Commands:
   Op Code: 01 (VCP Request)
   Op Code: 02 (VCP Response)
   Op Code: 03 (VCP Set)
   Op Code: 07 (Timing Request)
   Op Code: 0C (Save Settings)
   Op Code: E3 (Capabilities Reply)
   Op Code: F3 (Capabilities Request)
VCP Features:
   Feature: 02 (New control value)
   Feature: 04 (Restore factory defaults)
   Feature: 05 (Restore factory brightness/contrast defaults)
   Feature: 08 (Restore color defaults)
   Feature: 10 (Brightness)
   Feature: 12 (Contrast)
   Feature: 14 (Select color preset)
      Values:
         05: 6500 K
         06: 7500 K
         08: 9300 K
         0b: User 1
   Feature: 16 (Video gain: Red)
   Feature: 18 (Video gain: Green)
   Feature: 1A (Video gain: Blue)
   Feature: 3E (Clock phase)
   Feature: 52 (Active control)
   Feature: 60 (Input Source)
      Values:
         01: VGA-1
         03: DVI-1
   Feature: 6C (Video black level: Red)
   Feature: 6E (Video black level: Green)
   Feature: 70 (Video black level: Blue)
   Feature: AC (Horizontal frequency)
   Feature: AE (Vertical frequency)
   Feature: B2 (Flat panel sub-pixel layout)
   Feature: B6 (Display technology type)
   Feature: C0 (Display usage time)
   Feature: C8 (Display controller type)
   Feature: C9 (Display firmware level)
   Feature: CC (OSD Language)
      Values:
         01: Chinese (traditional, Hantai)
         02: English
         03: French
         04: German
         05: Italian
         06: Japanese
         09: Russian
         0a: Spanish
   Feature: D6 (Power mode)
      Values:
         01: DPM: On,  DPMS: Off
         05: Write only value to turn off display
   Feature: DF (VCP Version)

=====> Starting loop 4
FORMAT 2
* DEV  /dev/i2c device
* EC   EDID check sum byte
* C    current step
* I    interval remaining
* L    current lookback
* DEV EC C I L Values
* Values {tries required, step, epoch seconds}
i2c-0 3d 5 3 6 {1,7,1689307308} {1,7,1689307308} {1,7,1689307321} {1,7,1689307321} {1,7,1689307334} {1,6,1689307334}
i2c-1 2a 10 3 20 {1,3,1689307341} {1,2,1689307341} {1,1,1689307342} {1,0,1689307342} {1,0,1689307342} {1,0,1689307342} {1,0,1689307343} {1,0,1689307343} {1,0,1689307343} {1,0,1689307343} {1,0,1689307344} {1,0,1689307344} {1,0,1689307344} {1,0,1689307344} {1,0,1689307345} {1,0,1689307345} {1,0,1689307345} {1,0,1689307345} {1,0,1689307346} {1,0,1689307346}
i2c-3 9e 5 3 6 {1,7,1689307312} {1,7,1689307312} {1,7,1689307326} {1,7,1689307326} {1,7,1689307339} {1,6,1689307339}

/home/michael/bin/ddcutil --display 2 --noconfig --tid --ts --disable-capabilities-cache --enable-dynamic-sleep cap
Model: T2200HD
MCCS version: 2.0
Commands:
   Op Code: 01 (VCP Request)
   Op Code: 02 (VCP Response)
   Op Code: 03 (VCP Set)
   Op Code: 07 (Timing Request)
   Op Code: 0C (Save Settings)
   Op Code: E3 (Capabilities Reply)
   Op Code: F3 (Capabilities Request)
VCP Features:
   Feature: 02 (New control value)
   Feature: 04 (Restore factory defaults)
   Feature: 05 (Restore factory brightness/contrast defaults)
   Feature: 08 (Restore color defaults)
   Feature: 10 (Brightness)
   Feature: 12 (Contrast)
   Feature: 14 (Select color preset)
      Values:
         05: 6500 K
         06: 7500 K
         08: 9300 K
         0b: User 1
   Feature: 16 (Video gain: Red)
   Feature: 18 (Video gain: Green)
   Feature: 1A (Video gain: Blue)
   Feature: 3E (Clock phase)
   Feature: 52 (Active control)
   Feature: 60 (Input Source)
      Values:
         01: VGA-1
         03: DVI-1
   Feature: 6C (Video black level: Red)
   Feature: 6E (Video black level: Green)
   Feature: 70 (Video black level: Blue)
   Feature: AC (Horizontal frequency)
   Feature: AE (Vertical frequency)
   Feature: B2 (Flat panel sub-pixel layout)
   Feature: B6 (Display technology type)
   Feature: C0 (Display usage time)
   Feature: C8 (Display controller type)
   Feature: C9 (Display firmware level)
   Feature: CC (OSD Language)
      Values:
         01: Chinese (traditional, Hantai)
         02: English
         03: French
         04: German
         05: Italian
         06: Japanese
         09: Russian
         0a: Spanish
   Feature: D6 (Power mode)
      Values:
         01: DPM: On,  DPMS: Off
         05: Write only value to turn off display
   Feature: DF (VCP Version)

=====> Starting loop 5
FORMAT 2
* DEV  /dev/i2c device
* EC   EDID check sum byte
* C    current step
* I    interval remaining
* L    current lookback
* DEV EC C I L Values
* Values {tries required, step, epoch seconds}
i2c-0 3d 3 3 8 {1,7,1689307308} {1,7,1689307308} {1,7,1689307321} {1,7,1689307321} {1,7,1689307334} {1,6,1689307334} {1,5,1689307346} {1,4,1689307347}
i2c-1 2a 10 3 20 {1,3,1689307354} {1,2,1689307354} {1,1,1689307354} {1,0,1689307354} {1,0,1689307355} {1,0,1689307355} {1,0,1689307355} {1,0,1689307355} {1,0,1689307356} {1,0,1689307356} {1,0,1689307356} {1,0,1689307356} {1,0,1689307357} {1,0,1689307357} {1,0,1689307357} {1,0,1689307357} {1,0,1689307358} {1,0,1689307358} {1,0,1689307358} {1,0,1689307358}
i2c-3 9e 3 3 8 {1,7,1689307312} {1,7,1689307312} {1,7,1689307326} {1,7,1689307326} {1,7,1689307339} {1,6,1689307339} {1,5,1689307351} {1,4,1689307351}

/home/michael/bin/ddcutil --display 2 --noconfig --tid --ts --disable-capabilities-cache --enable-dynamic-sleep cap
Model: T2200HD
MCCS version: 2.0
Commands:
   Op Code: 01 (VCP Request)
   Op Code: 02 (VCP Response)
   Op Code: 03 (VCP Set)
   Op Code: 07 (Timing Request)
   Op Code: 0C (Save Settings)
   Op Code: E3 (Capabilities Reply)
   Op Code: F3 (Capabilities Request)
VCP Features:
   Feature: 02 (New control value)
   Feature: 04 (Restore factory defaults)
   Feature: 05 (Restore factory brightness/contrast defaults)
   Feature: 08 (Restore color defaults)
   Feature: 10 (Brightness)
   Feature: 12 (Contrast)
   Feature: 14 (Select color preset)
      Values:
         05: 6500 K
         06: 7500 K
         08: 9300 K
         0b: User 1
   Feature: 16 (Video gain: Red)
   Feature: 18 (Video gain: Green)
   Feature: 1A (Video gain: Blue)
   Feature: 3E (Clock phase)
   Feature: 52 (Active control)
   Feature: 60 (Input Source)
      Values:
         01: VGA-1
         03: DVI-1
   Feature: 6C (Video black level: Red)
   Feature: 6E (Video black level: Green)
   Feature: 70 (Video black level: Blue)
   Feature: AC (Horizontal frequency)
   Feature: AE (Vertical frequency)
   Feature: B2 (Flat panel sub-pixel layout)
   Feature: B6 (Display technology type)
   Feature: C0 (Display usage time)
   Feature: C8 (Display controller type)
   Feature: C9 (Display firmware level)
   Feature: CC (OSD Language)
      Values:
         01: Chinese (traditional, Hantai)
         02: English
         03: French
         04: German
         05: Italian
         06: Japanese
         09: Russian
         0a: Spanish
   Feature: D6 (Power mode)
      Values:
         01: DPM: On,  DPMS: Off
         05: Write only value to turn off display
   Feature: DF (VCP Version)

=====> Starting loop 6
FORMAT 2
* DEV  /dev/i2c device
* EC   EDID check sum byte
* C    current step
* I    interval remaining
* L    current lookback
* DEV EC C I L Values
* Values {tries required, step, epoch seconds}
i2c-0 3d 1 3 10 {1,7,1689307308} {1,7,1689307308} {1,7,1689307321} {1,7,1689307321} {1,7,1689307334} {1,6,1689307334} {1,5,1689307346} {1,4,1689307347} {1,3,1689307359} {1,2,1689307359}
i2c-1 2a 10 3 20 {1,3,1689307366} {1,2,1689307366} {1,1,1689307367} {1,0,1689307367} {1,0,1689307367} {1,0,1689307367} {1,0,1689307368} {1,0,1689307368} {1,0,1689307368} {1,0,1689307368} {1,0,1689307369} {1,0,1689307369} {1,0,1689307369} {1,0,1689307369} {1,0,1689307370} {1,0,1689307370} {1,0,1689307370} {1,0,1689307370} {1,0,1689307371} {1,0,1689307371}
i2c-3 9e 1 3 10 {1,7,1689307312} {1,7,1689307312} {1,7,1689307326} {1,7,1689307326} {1,7,1689307339} {1,6,1689307339} {1,5,1689307351} {1,4,1689307351} {1,3,1689307364} {1,2,1689307364}
rockowitz commented 1 year ago

Passing --f7 on the command line works for me: 

rock@banner:/shared/playproj/i2c$ ./test_dsa_cap --f7
rm: cannot remove '/home/rock/.cache/ddcutil/dsa': No such file or directory

=====> Starting loop 1
cat: /home/rock/.cache/ddcutil/dsa: No such file or directory

src/ddcutil --noconfig --tid --ts --disable-capabilities-cache --enable-dynamic-sleep cap --f7
Model: Not specified
MCCS version: 2.1
VCP Features:
   Feature: 02 (New control value)
   Feature: 04 (Restore factory defaults)
   Feature: 05 (Restore factory brightness/contrast defaults)
digitaltrails commented 1 year ago

Passing --f7 on the command line works for me:

rock@banner:/shared/playproj/i2c$ ./test_dsa_cap --f7
rm: cannot remove '/home/rock/.cache/ddcutil/dsa': No such file or directory

=====> Starting loop 1
cat: /home/rock/.cache/ddcutil/dsa: No such file or directory

src/ddcutil --noconfig --tid --ts --disable-capabilities-cache --enable-dynamic-sleep cap --f7
Model: Not specified
MCCS version: 2.1
VCP Features:
   Feature: 02 (New control value)
   Feature: 04 (Restore factory defaults)
   Feature: 05 (Restore factory brightness/contrast defaults)

It was more that the script you asked me to run didn't actually pass --f7, but I can edit that in and run it again.

rockowitz commented 1 year ago

Try adding --trcfunc ddc_initial_checks_by_dh. DREF_DDC_USES_DDC_FLAG_FOR_UNSUPPORTED should be set, not some other DREFDDC...FOR_UNSUPPORTED flag.

digitaltrails commented 1 year ago

DREF_DDC_USES_DDC_FLAG_FOR_UNSUPPORTED

I restarted passing --f7 and --trcfunc ddc_initial_checks_by_dh, it is reporting DREF_DDC_USES_DDC_FLAG_FOR_UNSUPPORTED at startup. It seems to be looping fine, 14 iterations so far.

digitaltrails commented 1 year ago

This is the log from the above. It never failed I terminated the run.

f7-log.zip

digitaltrails commented 1 year ago

The latest build is quite slow with other (non-Beng) monitors. For example with my LG Ddcutil-2dev takes above 5 seconds to do a getvcp compared to ddcutil-2rc1 which takes about 0.28.

% time ~/bin/ddcutil --display 3 getvcp 10;cat ~/.cache/ddcutil/dsa 
VCP code 0x10 (Brightness                    ): current value =    43, max value =   100
~/bin/ddcutil --display 3 getvcp 10  0.01s user 0.46s system 8% cpu 5.559 total
FORMAT 2
* DEV  /dev/i2c device
* EC   EDID check sum byte
* C    current step
* I    interval remaining
* L    current lookback
* DEV EC C I L Values
* Values {tries required, step, epoch seconds}
i2c-0 3d 0 3 5 {1,0,1689318932} {1,0,1689318932} {1,0,1689318945} {1,0,1689318945} {1,0,1689318952} {1,0,1689318952} {1,0,1689319024} {1,0,1689319025} {1,0,1689319067} {1,0,1689319067} {1,0,1689319081} {1,0,1689319081} {1,0,1689319113} {1,0,1689319114} {1,0,1689319219} {1,0,1689319220} {1,0,1689319227} {1,0,1689319228} {1,0,1689319249} {1,0,1689319249}
i2c-1 2a 10 3 20 {1,10,1689318936} {1,9,1689318936} {1,10,1689318949} {1,9,1689318949} {1,10,1689318956} {1,9,1689318957} {1,10,1689319029} {1,9,1689319029} {1,10,1689319071} {1,9,1689319071} {1,10,1689319083} {1,9,1689319083} {1,10,1689319117} {1,9,1689319117} {1,10,1689319224} {1,9,1689319224} {1,10,1689319232} {1,9,1689319232} {1,10,1689319253} {1,9,1689319253}
i2c-3 9e 0 3 5 {1,0,1689319072} {1,0,1689319072} {1,0,1689319072} {1,0,1689319083} {1,0,1689319083} {1,0,1689319083} {1,0,1689319092} {1,0,1689319109} {1,0,1689319118} {1,0,1689319118} {1,0,1689319118} {1,0,1689319224} {1,0,1689319224} {1,0,1689319225} {1,0,1689319232} {1,0,1689319232} {1,0,1689319232} {1,0,1689319253} {1,0,1689319253} {1,0,1689319254}

versus

rm ~/.cache/ddcutil/dsa; time ~/bin/ddcutil-2rc1 --display 3 getvcp 10;cat ~/.cache/ddcutil/dsa
VCP code 0x10 (Brightness                    ): current value =    43, max value =   100
~/bin/ddcutil-2rc1 --display 3 getvcp 10  0.01s user 0.27s system 73% cpu 0.379 total
FORMAT 2
* DEV  /dev/i2c device
* EC   EDID check sum byte
* C    current step
* I    interval remaining
* DEV EC C I Values
* Values {tries required, step, epoch seconds}
i2c-0 3d 7 3 5
i2c-1 2a 7 3 5
i2c-3 9e 7 3 5 {1,7,1689319337}
rockowitz commented 1 year ago

Re f7.log:

1) The monitor is responding to getvcp of feature 0x00 with Null Messages instead of setting the unsupported flag bit in a getvcp reply packet, and consequently setting flag DREF_DDC_USES_NULL_RESPONSE_FOR_UNSUPPORTED instead of DREF_DDC_USES_DDC_FLAG_FOR_UNSUPPORTED. If this is incorrect, it will likely cause Null Messages to be misinterpreted down the line. (It does not affect the capabilities command because I have modified multi_part_read_with_retry() to not check for an unsupported feature when it is called for the capabilities command.)

Does this behaviour persist with option --disable-dynamic-sleep?

2) The number of tries in the case of repeated Null Responses has been reduced from the maxtries value, normally 10, to 3, greatly reducing the elapsed time in this case. 3 tries is sufficient to determine that the Null Response is not transient.

rockowitz commented 1 year ago

Re the elapsed time for getvcp of feature x10:

1) Once dsa2 has adjusted to a maximal sleep-multiplier it is not adjusting back down. Obviously this needs to be fixed.

2) I suggest you use option ---bus instead of --display to specify the monitor. as this is easier to correlate with the cache file data. Also, indicate which is the Benq or other monitor in these logs.

digitaltrails commented 1 year ago

Info on connected monitors:

Display 1
   I2C bus:  /dev/i2c-0
   DRM connector:           card0-DP-1
   EDID synopsis:
      Mfg id:               HWP - Hewlett Packard
      Model:                HP ZR24w
      Product code:         10345  (0x2869)
      Serial number:        CNT00811J6
      Binary serial number: 16843009 (0x01010101)
      Manufacture year:     2010,  Week: 8
   VCP version:         2.2

Display 2
   I2C bus:  /dev/i2c-1
   DRM connector:           card0-DP-2
   EDID synopsis:
      Mfg id:               BNQ - UNK
      Model:                BenQ T2200HD
      Product code:         30502  (0x7726)
      Serial number:        2C803527SL0
      Binary serial number: 21573 (0x00005445)
      Manufacture year:     2008,  Week: 51
   VCP version:         2.0

Display 3
   I2C bus:  /dev/i2c-3
   DRM connector:           card0-DP-3
   EDID synopsis:
      Mfg id:               GSM - Goldstar Company Ltd (LG)
      Model:                LG HDR 4K
      Product code:         30471  (0x7707)
      Serial number:        
      Binary serial number: 86395 (0x0001517b)
      Manufacture year:     2019,  Week: 4
   VCP version:         2.1
digitaltrails commented 1 year ago

Re the elapsed time for getvcp of feature x10:

  1. Once dsa2 has adjusted to a maximal sleep-multiplier it is not adjusting back down. Obviously this needs to be fixed.

So that's why I see the time reduce when using ddcutil-2rc1, but not with ddcutil-dev. But it's not as bad as I previously stated. I forgot I had previously added my own sleep to see if overloading the Beng was the issue, this was affecting results for all monitors. I've removed my hack, now the dev elapsed time fixes to 1.624 seconds (whereas rc1 gets it down to 0.282 seconds).

  1. I suggest you use option ---bus instead of --display to specify the monitor. as this is easier to correlate with the cache file data. Also, indicate which is the Benq or other monitor in these logs.

Will do.

digitaltrails commented 1 year ago

Re f7.log:

  1. The monitor is responding to getvcp of feature 0x00 with Null Messages instead of setting the unsupported flag bit in a getvcp reply packet, and consequently setting flag DREF_DDC_USES_NULL_RESPONSE_FOR_UNSUPPORTED instead of DREF_DDC_USES_DDC_FLAG_FOR_UNSUPPORTED. If this is incorrect, it will likely cause Null Messages to be misinterpreted down the line. (It does not affect the capabilities command because I have modified multi_part_read_with_retry() to not check for an unsupported feature when it is called for the capabilities command.)

Does this behaviour persist with option --disable-dynamic-sleep?

I reran the test script with --disable-dynamic-sleep with no other changes other than using --bus, the command line in the test is as follows:

/home/michael/bin/ddcutil-dev --bus 1 --noconfig --disable-dynamic-sleep --f7 --trcfunc ddc_initial_checks_by_dh --tid --ts --disable-capabilities-cache --enable-dynamic-sleep cap

a log of few iterations is attached. f7--disable-dynamic-sleep.zip

rockowitz commented 1 year ago

As f7-disable-dynamic-sleep.log shows, the Benq monitor appears to use the Null Message to indicate unsupported features. To confirm, try:

ddcutil --bus 1 --noconfig --disable-dynamic-sleep --f7 --trcfunc ddc_initial_checks_by_dh --trcfunc ddc_get_nontable_vcp_value --trcfunc i2c_ioctl_reader1 getvcp 41

(Feature x41 applies only to CRTs. It should be unsupported.)

digitaltrails commented 1 year ago

To confirm, try:

ddcutil --bus 1 --noconfig --disable-dynamic-sleep --f7 --trcfunc ddc_initial_checks_by_dh --trcfunc ddc_get_nontable_vcp_value --trcfunc i2c_ioctl_reader1 getvcp 41

./src/ddcutil --bus 1 --noconfig --disable-dynamic-sleep --f7 --trcfunc ddc_initial_checks_by_dh --trcfunc ddc_get_nontable_vcp_value --trcfunc i2c_ioctl_reader1 getvcp 41
(ddc_initial_checks_by_dh      ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x55a9d709b320]
(ddc_initial_checks_by_dh      )           Initial flags: DREF_DDC_IS_MONITOR_CHECKED, DREF_DDC_IS_MONITOR, DREF_TRANSIENT, DREF_OPEN, DREF_ALIVE
(ddc_get_nontable_vcp_value    ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x55a9d709b320], Reading feature 0x00
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x55a9d709b5d0
   i2c_rdwr_ioctl_data at: 0x7ffd0e8ecda0
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x55a9d709b5d0 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 80 be 6e 80 be 6e 80 be 6e 80 be
(adjust_sleep_time             )           Adding 100 milliseconds for 1 Null response(s), busno=1, event_type=SE_WRITE_TO_READ, adjusted_sleep_time=150 
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x55a9d709b9d0
   i2c_rdwr_ioctl_data at: 0x7ffd0e8ecda0
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x55a9d709b9d0 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 80 be 6e 80 be 6e 80 be 6e 80 be
(adjust_sleep_time             )           Adding 100 milliseconds for 1 Null response(s), busno=1, event_type=SE_POST_READ, adjusted_sleep_time=150 
(adjust_sleep_time             )           Adding 200 milliseconds for 2 Null response(s), busno=1, event_type=SE_WRITE_TO_READ, adjusted_sleep_time=250 
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x55a9d709bbe0
   i2c_rdwr_ioctl_data at: 0x7ffd0e8ecda0
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x55a9d709bbe0 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 80 be 6e 80 be 6e 80 be 6e 80 be
(adjust_sleep_time             )           Adding 200 milliseconds for 2 Null response(s), busno=1, event_type=SE_POST_READ, adjusted_sleep_time=250 
(adjust_sleep_time             )           Adding 300 milliseconds for 3 Null response(s), busno=1, event_type=SE_WRITE_TO_READ, adjusted_sleep_time=350 
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x55a9d709bc70
   i2c_rdwr_ioctl_data at: 0x7ffd0e8ecda0
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x55a9d709bc70 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 80 be 6e 80 be 6e 80 be 6e 80 be
(adjust_sleep_time             )           Adding 300 milliseconds for 3 Null response(s), busno=1, event_type=SE_POST_READ, adjusted_sleep_time=350 
(ddc_get_nontable_vcp_value    )           ddc_write_read_with_retry() returned DDCRC_ALL_RESPONSES_NULL(-3011): all tries returned DDC Null Message, response_packet_ptr=(nil)
(ddc_get_nontable_vcp_value    ) Done      Returning: Error_Info[DDCRC_ALL_RESPONSES_NULL in ddc_write_read_with_retry, causes: DDCRC_NULL_RESPONSE(4)]. 
(ddc_initial_checks_by_dh      )           ddc_get_nontable_vcp_value() for feature 0x00 returned: Error_Info[DDCRC_ALL_RESPONSES_NULL in ddc_write_read_with_retry, causes: DDCRC_NULL_RESPONSE(4)], parsed_response_loc=(nil)
(ddc_get_nontable_vcp_value    ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x55a9d709b320], Reading feature 0x10
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x55a9d709c0d0
   i2c_rdwr_ioctl_data at: 0x7ffd0e8ecda0
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x55a9d709c0d0 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 88 02 00 10 00 00 64 00 64 a4 6e
(ddc_get_nontable_vcp_value    )           Success reading feature x10. *ppinterpreted_code=0x55a9d709c0d0
(ddc_get_nontable_vcp_value    )           mh=0x00, ml=0x64, sh=0x00, sl=0x64, max value=100, cur value=100
(ddc_get_nontable_vcp_value    ) Done      Returning: NULL. 
(ddc_initial_checks_by_dh      )           ddc_get_nontable_vcp_value() for feature 0x10 returned: NULL
(ddc_get_nontable_vcp_value    ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x55a9d709b320], Reading feature 0xdf
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x55a9d709bbe0
   i2c_rdwr_ioctl_data at: 0x7ffd0e8ecd10
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x55a9d709bbe0 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 88 02 00 df 00 ff ff 02 00 69 6e
(ddc_get_nontable_vcp_value    )           Success reading feature xdf. *ppinterpreted_code=0x55a9d709c0d0
(ddc_get_nontable_vcp_value    )           mh=0xff, ml=0xff, sh=0x02, sl=0x00, max value=65535, cur value=512
(ddc_get_nontable_vcp_value    ) Done      Returning: NULL. 
(ddc_initial_checks_by_dh      )           Final flags: DREF_DDC_COMMUNICATION_CHECKED, DREF_DDC_COMMUNICATION_WORKING, DREF_DDC_IS_MONITOR_CHECKED, DREF_DDC_IS_MONITOR, DREF_UNSUPPORTED_CHECKED, DREF_DDC_USES_NULL_RESPONSE_FOR_UNSUPPORTED, DREF_TRANSIENT, DREF_OPEN, DREF_ALIVE
(ddc_initial_checks_by_dh      ) Done      Returning: true. dh=Display_Handle[i2c-1: fd=3 @0x55a9d709b320]
(ddc_get_nontable_vcp_value    ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x55a9d709b320], Reading feature 0x41
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x55a9d709bbe0
   i2c_rdwr_ioctl_data at: 0x7ffd0e8eca90
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x55a9d709bbe0 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 80 be 6e 80 be 6e 80 be 6e 80 be
(ddc_get_nontable_vcp_value    )           ddc_write_read_with_retry() returned DDCRC_ALL_RESPONSES_NULL(-3011): all tries returned DDC Null Message, response_packet_ptr=(nil)
(ddc_get_nontable_vcp_value    ) Done      Returning: Error_Info[DDCRC_ALL_RESPONSES_NULL in ddc_write_read_with_retry, causes: DDCRC_NULL_RESPONSE]. 
VCP code 0x41 (Vertical Parallelogram        ): Invalid response. status code=DDCRC_ALL_RESPONSES_NULL(-3011), Display_Handle[i2c-1: fd=3 @0x55a9d709b320]
rockowitz commented 1 year ago

Well, it certainly looks like the monitor is indeed using the Null Response to indicate an unsupported feature. As confirmation of the confirmation, please execute the script again using "getvcp color --verbose" instead of "getvcp 41". Feature group color should have a mix of supported and unsupported features, and option --verbose causes messages to be output for unsupported features.

The conundrum in this situation is how best to handle a Null Response. Does a particular Null Response indicate an unsupported feature or a monitor error. If the former, repeatedly retrying for the latter needlessly increases execution time and can drive up the sleep-multiplier calculated by dynamic sleep.

digitaltrails commented 1 year ago

Confirmation test:

% ddcutil --bus 1 --noconfig --disable-dynamic-sleep --f7 --trcfunc ddc_initial_checks_by_dh --trcfunc ddc_get_nontable_vcp_value --trcfunc i2c_ioctl_reader1 getvcp color --verbose 2>&1 1>test-color.log
(ddc_initial_checks_by_dh      ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x557eaa147750]
(ddc_initial_checks_by_dh      )           Initial flags: DREF_DDC_IS_MONITOR_CHECKED, DREF_DDC_IS_MONITOR, DREF_TRANSIENT, DREF_OPEN, DREF_ALIVE
(ddc_get_nontable_vcp_value    ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x557eaa147750], Reading feature 0x00
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x557eaa148a10
   i2c_rdwr_ioctl_data at: 0x7ffc4376a740
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x557eaa148a10 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 80 be 6e 80 be 6e 80 be 6e 80 be
Extended delay as recovery from DDC Null Response...
(adjust_sleep_time             )           Adding 100 milliseconds for 1 Null response(s), busno=1, event_type=SE_WRITE_TO_READ, adjusted_sleep_time=150 
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x557eaa148e10
   i2c_rdwr_ioctl_data at: 0x7ffc4376a740
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x557eaa148e10 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 80 be 6e 80 be 6e 80 be 6e 80 be
(adjust_sleep_time             )           Adding 100 milliseconds for 1 Null response(s), busno=1, event_type=SE_POST_READ, adjusted_sleep_time=150 
(adjust_sleep_time             )           Adding 200 milliseconds for 2 Null response(s), busno=1, event_type=SE_WRITE_TO_READ, adjusted_sleep_time=250 
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x557eaa149020
   i2c_rdwr_ioctl_data at: 0x7ffc4376a740
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x557eaa149020 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 80 be 6e 80 be 6e 80 be 6e 80 be
(adjust_sleep_time             )           Adding 200 milliseconds for 2 Null response(s), busno=1, event_type=SE_POST_READ, adjusted_sleep_time=250 
(adjust_sleep_time             )           Adding 300 milliseconds for 3 Null response(s), busno=1, event_type=SE_WRITE_TO_READ, adjusted_sleep_time=350 
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x557eaa1490b0
   i2c_rdwr_ioctl_data at: 0x7ffc4376a740
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x557eaa1490b0 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 80 be 6e 80 be 6e 80 be 6e 80 be
(adjust_sleep_time             )           Adding 300 milliseconds for 3 Null response(s), busno=1, event_type=SE_POST_READ, adjusted_sleep_time=350 
(ddc_get_nontable_vcp_value    )           ddc_write_read_with_retry() returned DDCRC_ALL_RESPONSES_NULL(-3011): all tries returned DDC Null Message, response_packet_ptr=(nil)
(ddc_get_nontable_vcp_value    ) Done      Returning: Error_Info[DDCRC_ALL_RESPONSES_NULL in ddc_write_read_with_retry, causes: DDCRC_NULL_RESPONSE(4)]. 
(ddc_initial_checks_by_dh      )           ddc_get_nontable_vcp_value() for feature 0x00 returned: Error_Info[DDCRC_ALL_RESPONSES_NULL in ddc_write_read_with_retry, causes: DDCRC_NULL_RESPONSE(4)], parsed_response_loc=(nil)
(ddc_get_nontable_vcp_value    ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x557eaa147750], Reading feature 0x10
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x557eaa149510
   i2c_rdwr_ioctl_data at: 0x7ffc4376a740
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x557eaa149510 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 88 02 00 10 00 00 64 00 63 a3 6e
(ddc_get_nontable_vcp_value    )           Success reading feature x10. *ppinterpreted_code=0x557eaa149510
(ddc_get_nontable_vcp_value    )           mh=0x00, ml=0x64, sh=0x00, sl=0x63, max value=100, cur value=99
(ddc_get_nontable_vcp_value    ) Done      Returning: NULL. 
(ddc_initial_checks_by_dh      )           ddc_get_nontable_vcp_value() for feature 0x10 returned: NULL
(ddc_get_nontable_vcp_value    ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x557eaa147750], Reading feature 0xdf
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x557eaa149020
   i2c_rdwr_ioctl_data at: 0x7ffc4376a6b0
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x557eaa149020 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 88 02 00 df 00 ff ff 02 00 69 6e
(ddc_get_nontable_vcp_value    )           Success reading feature xdf. *ppinterpreted_code=0x557eaa149510
(ddc_get_nontable_vcp_value    )           mh=0xff, ml=0xff, sh=0x02, sl=0x00, max value=65535, cur value=512
(ddc_get_nontable_vcp_value    ) Done      Returning: NULL. 
(ddc_initial_checks_by_dh      )           Final flags: DREF_DDC_COMMUNICATION_CHECKED, DREF_DDC_COMMUNICATION_WORKING, DREF_DDC_IS_MONITOR_CHECKED, DREF_DDC_IS_MONITOR, DREF_UNSUPPORTED_CHECKED, DREF_DDC_USES_NULL_RESPONSE_FOR_UNSUPPORTED, DREF_TRANSIENT, DREF_OPEN, DREF_ALIVE
(ddc_initial_checks_by_dh      ) Done      Returning: true. dh=Display_Handle[i2c-1: fd=3 @0x557eaa147750]
Feature definition file not found: BNQ-BenQ_T2200HD-30502.mccs
VCP code 0x04 (Restore factory defaults      ): Write-only feature
VCP code 0x05 (Restore factory brightness/contrast defaults): Write-only feature
VCP code 0x08 (Restore color defaults        ): Write-only feature

Getting data for non-table VCP code 0x0b - Color temperature increment:
(ddc_get_nontable_vcp_value    ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x557eaa147750], Reading feature 0x0b
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x557eaa149b80
   i2c_rdwr_ioctl_data at: 0x7ffc4376a380
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x557eaa149b80 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 88 02 00 0b 00 00 02 00 02 bf 6e
(ddc_get_nontable_vcp_value    )           Success reading feature x0b. *ppinterpreted_code=0x557eaa149b80
(ddc_get_nontable_vcp_value    )           mh=0x00, ml=0x02, sh=0x00, sl=0x02, max value=2, cur value=2
(ddc_get_nontable_vcp_value    ) Done      Returning: NULL. 
Raw value: opcode=0x0b, mh=0x00, ml=0x02, sh=0x00, sl=0x02, max_val=2 (0x0002), cur_val=2 (0x0002)
VCP code 0x0b (Color temperature increment   ): 2 degree(s) Kelvin

Getting data for non-table VCP code 0x0c - Color temperature request:
(ddc_get_nontable_vcp_value    ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x557eaa147750], Reading feature 0x0c
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x557eaa149d30
   i2c_rdwr_ioctl_data at: 0x7ffc4376a380
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x557eaa149d30 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 88 02 00 0c 00 00 02 00 02 b8 6e
(ddc_get_nontable_vcp_value    )           Success reading feature x0c. *ppinterpreted_code=0x557eaa149d30
(ddc_get_nontable_vcp_value    )           mh=0x00, ml=0x02, sh=0x00, sl=0x02, max value=2, cur value=2
(ddc_get_nontable_vcp_value    ) Done      Returning: NULL. 
Raw value: opcode=0x0c, mh=0x00, ml=0x02, sh=0x00, sl=0x02, max_val=2 (0x0002), cur_val=2 (0x0002)
VCP code 0x0c (Color temperature request     ): 3000 + 2 * (feature 0B color temp increment) degree(s) Kelvin

Getting data for non-table VCP code 0x10 - Brightness:
(ddc_get_nontable_vcp_value    ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x557eaa147750], Reading feature 0x10
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x557eaa149d30
   i2c_rdwr_ioctl_data at: 0x7ffc4376a380
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x557eaa149d30 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 88 02 00 10 00 00 64 00 63 a3 6e
(ddc_get_nontable_vcp_value    )           Success reading feature x10. *ppinterpreted_code=0x557eaa149d10
(ddc_get_nontable_vcp_value    )           mh=0x00, ml=0x64, sh=0x00, sl=0x63, max value=100, cur value=99
(ddc_get_nontable_vcp_value    ) Done      Returning: NULL. 
Raw value: opcode=0x10, mh=0x00, ml=0x64, sh=0x00, sl=0x63, max_val=100 (0x0064), cur_val=99 (0x0063)
VCP code 0x10 (Brightness                    ): current value =    99, max value =   100

Getting data for non-table VCP code 0x11 - Flesh tone enhancement:
(ddc_get_nontable_vcp_value    ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x557eaa147750], Reading feature 0x11
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x557eaa149d10
   i2c_rdwr_ioctl_data at: 0x7ffc4376a380
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x557eaa149d10 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 80 be 6e 80 be 6e 80 be 6e 80 be
(ddc_get_nontable_vcp_value    )           ddc_write_read_with_retry() returned DDCRC_ALL_RESPONSES_NULL(-3011): all tries returned DDC Null Message, response_packet_ptr=(nil)
(ddc_get_nontable_vcp_value    ) Done      Returning: Error_Info[DDCRC_ALL_RESPONSES_NULL in ddc_write_read_with_retry, causes: DDCRC_NULL_RESPONSE]. 
VCP code 0x11 (Flesh tone enhancement        ): Invalid response. status code=DDCRC_ALL_RESPONSES_NULL(-3011), Display_Handle[i2c-1: fd=3 @0x557eaa147750]

Getting data for non-table VCP code 0x12 - Contrast:
(ddc_get_nontable_vcp_value    ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x557eaa147750], Reading feature 0x12
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x557eaa149d10
   i2c_rdwr_ioctl_data at: 0x7ffc4376a380
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x557eaa149d10 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 88 02 00 12 00 00 64 00 32 f0 6e
(ddc_get_nontable_vcp_value    )           Success reading feature x12. *ppinterpreted_code=0x557eaa149eb0
(ddc_get_nontable_vcp_value    )           mh=0x00, ml=0x64, sh=0x00, sl=0x32, max value=100, cur value=50
(ddc_get_nontable_vcp_value    ) Done      Returning: NULL. 
Raw value: opcode=0x12, mh=0x00, ml=0x64, sh=0x00, sl=0x32, max_val=100 (0x0064), cur_val=50 (0x0032)
VCP code 0x12 (Contrast                      ): current value =    50, max value =   100

Getting data for non-table VCP code 0x13 - Backlight control:
(ddc_get_nontable_vcp_value    ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x557eaa147750], Reading feature 0x13
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x557eaa149eb0
   i2c_rdwr_ioctl_data at: 0x7ffc4376a380
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x557eaa149eb0 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 80 be 6e 80 be 6e 80 be 6e 80 be
(ddc_get_nontable_vcp_value    )           ddc_write_read_with_retry() returned DDCRC_ALL_RESPONSES_NULL(-3011): all tries returned DDC Null Message, response_packet_ptr=(nil)
(ddc_get_nontable_vcp_value    ) Done      Returning: Error_Info[DDCRC_ALL_RESPONSES_NULL in ddc_write_read_with_retry, causes: DDCRC_NULL_RESPONSE]. 
VCP code 0x13 (Backlight control             ): Invalid response. status code=DDCRC_ALL_RESPONSES_NULL(-3011), Display_Handle[i2c-1: fd=3 @0x557eaa147750]

Getting data for non-table VCP code 0x14 - Select color preset:
(ddc_get_nontable_vcp_value    ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x557eaa147750], Reading feature 0x14
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x557eaa149eb0
   i2c_rdwr_ioctl_data at: 0x7ffc4376a380
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x557eaa149eb0 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 88 02 00 14 00 00 0b 00 0b a0 6e
(ddc_get_nontable_vcp_value    )           Success reading feature x14. *ppinterpreted_code=0x557eaa149d30
(ddc_get_nontable_vcp_value    )           mh=0x00, ml=0x0b, sh=0x00, sl=0x0b, max value=11, cur value=11
(ddc_get_nontable_vcp_value    ) Done      Returning: NULL. 
Raw value: opcode=0x14, mh=0x00, ml=0x0b, sh=0x00, sl=0x0b, max_val=11 (0x000b), cur_val=11 (0x000b)
VCP code 0x14 (Select color preset           ): User 1 (sl=0x0b)

Getting data for non-table VCP code 0x16 - Video gain: Red:
(ddc_get_nontable_vcp_value    ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x557eaa147750], Reading feature 0x16
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x557eaa149d30
   i2c_rdwr_ioctl_data at: 0x7ffc4376a380
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x557eaa149d30 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 88 02 00 16 00 00 64 00 64 a2 6e
(ddc_get_nontable_vcp_value    )           Success reading feature x16. *ppinterpreted_code=0x557eaa149da0
(ddc_get_nontable_vcp_value    )           mh=0x00, ml=0x64, sh=0x00, sl=0x64, max value=100, cur value=100
(ddc_get_nontable_vcp_value    ) Done      Returning: NULL. 
Raw value: opcode=0x16, mh=0x00, ml=0x64, sh=0x00, sl=0x64, max_val=100 (0x0064), cur_val=100 (0x0064)
VCP code 0x16 (Video gain: Red               ): current value =   100, max value =   100

Getting data for non-table VCP code 0x17 - User color vision compensation:
(ddc_get_nontable_vcp_value    ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x557eaa147750], Reading feature 0x17
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x557eaa149da0
   i2c_rdwr_ioctl_data at: 0x7ffc4376a380
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x557eaa149da0 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 80 be 6e 80 be 6e 80 be 6e 80 be
(ddc_get_nontable_vcp_value    )           ddc_write_read_with_retry() returned DDCRC_ALL_RESPONSES_NULL(-3011): all tries returned DDC Null Message, response_packet_ptr=(nil)
(ddc_get_nontable_vcp_value    ) Done      Returning: Error_Info[DDCRC_ALL_RESPONSES_NULL in ddc_write_read_with_retry, causes: DDCRC_NULL_RESPONSE]. 
VCP code 0x17 (User color vision compensation): Invalid response. status code=DDCRC_ALL_RESPONSES_NULL(-3011), Display_Handle[i2c-1: fd=3 @0x557eaa147750]

Getting data for non-table VCP code 0x18 - Video gain: Green:
(ddc_get_nontable_vcp_value    ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x557eaa147750], Reading feature 0x18
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x557eaa149da0
   i2c_rdwr_ioctl_data at: 0x7ffc4376a380
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x557eaa149da0 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 88 02 00 18 00 00 64 00 64 ac 6e
(ddc_get_nontable_vcp_value    )           Success reading feature x18. *ppinterpreted_code=0x557eaa149eb0
(ddc_get_nontable_vcp_value    )           mh=0x00, ml=0x64, sh=0x00, sl=0x64, max value=100, cur value=100
(ddc_get_nontable_vcp_value    ) Done      Returning: NULL. 
Raw value: opcode=0x18, mh=0x00, ml=0x64, sh=0x00, sl=0x64, max_val=100 (0x0064), cur_val=100 (0x0064)
VCP code 0x18 (Video gain: Green             ): current value =   100, max value =   100

Getting data for non-table VCP code 0x1a - Video gain: Blue:
(ddc_get_nontable_vcp_value    ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x557eaa147750], Reading feature 0x1a
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x557eaa149eb0
   i2c_rdwr_ioctl_data at: 0x7ffc4376a380
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x557eaa149eb0 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 88 02 00 1a 00 00 64 00 64 ae 6e
(ddc_get_nontable_vcp_value    )           Success reading feature x1a. *ppinterpreted_code=0x557eaa149d10
(ddc_get_nontable_vcp_value    )           mh=0x00, ml=0x64, sh=0x00, sl=0x64, max value=100, cur value=100
(ddc_get_nontable_vcp_value    ) Done      Returning: NULL. 
Raw value: opcode=0x1a, mh=0x00, ml=0x64, sh=0x00, sl=0x64, max_val=100 (0x0064), cur_val=100 (0x0064)
VCP code 0x1a (Video gain: Blue              ): current value =   100, max value =   100

Getting data for non-table VCP code 0x1f - Auto color setup:
(ddc_get_nontable_vcp_value    ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x557eaa147750], Reading feature 0x1f
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x557eaa149d10
   i2c_rdwr_ioctl_data at: 0x7ffc4376a380
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x557eaa149d10 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 88 02 00 1f 00 00 ff 00 00 54 6e
(ddc_get_nontable_vcp_value    )           Success reading feature x1f. *ppinterpreted_code=0x557eaa149d30
(ddc_get_nontable_vcp_value    )           mh=0x00, ml=0xff, sh=0x00, sl=0x00, max value=255, cur value=0
(ddc_get_nontable_vcp_value    ) Done      Returning: NULL. 
Raw value: opcode=0x1f, mh=0x00, ml=0xff, sh=0x00, sl=0x00, max_val=255 (0x00ff), cur_val=0 (0x0000)
VCP code 0x1f (Auto color setup              ): Auto setup not active (sl=0x00)

Getting data for non-table VCP code 0x2e - Gray scale expansion:
(ddc_get_nontable_vcp_value    ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x557eaa147750], Reading feature 0x2e
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x557eaa149d30
   i2c_rdwr_ioctl_data at: 0x7ffc4376a380
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x557eaa149d30 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 80 be 6e 80 be 6e 80 be 6e 80 be
(ddc_get_nontable_vcp_value    )           ddc_write_read_with_retry() returned DDCRC_ALL_RESPONSES_NULL(-3011): all tries returned DDC Null Message, response_packet_ptr=(nil)
(ddc_get_nontable_vcp_value    ) Done      Returning: Error_Info[DDCRC_ALL_RESPONSES_NULL in ddc_write_read_with_retry, causes: DDCRC_NULL_RESPONSE]. 
VCP code 0x2e (Gray scale expansion          ): Invalid response. status code=DDCRC_ALL_RESPONSES_NULL(-3011), Display_Handle[i2c-1: fd=3 @0x557eaa147750]

Getting data for non-table VCP code 0x59 - 6 axis saturation: Red:
(ddc_get_nontable_vcp_value    ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x557eaa147750], Reading feature 0x59
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x557eaa149d30
   i2c_rdwr_ioctl_data at: 0x7ffc4376a380
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x557eaa149d30 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 80 be 6e 80 be 6e 80 be 6e 80 be
(ddc_get_nontable_vcp_value    )           ddc_write_read_with_retry() returned DDCRC_ALL_RESPONSES_NULL(-3011): all tries returned DDC Null Message, response_packet_ptr=(nil)
(ddc_get_nontable_vcp_value    ) Done      Returning: Error_Info[DDCRC_ALL_RESPONSES_NULL in ddc_write_read_with_retry, causes: DDCRC_NULL_RESPONSE]. 
VCP code 0x59 (6 axis saturation: Red        ): Invalid response. status code=DDCRC_ALL_RESPONSES_NULL(-3011), Display_Handle[i2c-1: fd=3 @0x557eaa147750]

Getting data for non-table VCP code 0x5a - 6 axis saturation: Yellow:
(ddc_get_nontable_vcp_value    ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x557eaa147750], Reading feature 0x5a
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x557eaa149d30
   i2c_rdwr_ioctl_data at: 0x7ffc4376a380
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x557eaa149d30 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 80 be 6e 80 be 6e 80 be 6e 80 be
(ddc_get_nontable_vcp_value    )           ddc_write_read_with_retry() returned DDCRC_ALL_RESPONSES_NULL(-3011): all tries returned DDC Null Message, response_packet_ptr=(nil)
(ddc_get_nontable_vcp_value    ) Done      Returning: Error_Info[DDCRC_ALL_RESPONSES_NULL in ddc_write_read_with_retry, causes: DDCRC_NULL_RESPONSE]. 
VCP code 0x5a (6 axis saturation: Yellow     ): Invalid response. status code=DDCRC_ALL_RESPONSES_NULL(-3011), Display_Handle[i2c-1: fd=3 @0x557eaa147750]

Getting data for non-table VCP code 0x5b - 6 axis saturation: Green:
(ddc_get_nontable_vcp_value    ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x557eaa147750], Reading feature 0x5b
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x557eaa149d30
   i2c_rdwr_ioctl_data at: 0x7ffc4376a380
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x557eaa149d30 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 80 be 6e 80 be 6e 80 be 6e 80 be
(ddc_get_nontable_vcp_value    )           ddc_write_read_with_retry() returned DDCRC_ALL_RESPONSES_NULL(-3011): all tries returned DDC Null Message, response_packet_ptr=(nil)
(ddc_get_nontable_vcp_value    ) Done      Returning: Error_Info[DDCRC_ALL_RESPONSES_NULL in ddc_write_read_with_retry, causes: DDCRC_NULL_RESPONSE]. 
VCP code 0x5b (6 axis saturation: Green      ): Invalid response. status code=DDCRC_ALL_RESPONSES_NULL(-3011), Display_Handle[i2c-1: fd=3 @0x557eaa147750]

Getting data for non-table VCP code 0x5c - 6 axis saturation: Cyan:
(ddc_get_nontable_vcp_value    ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x557eaa147750], Reading feature 0x5c
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x557eaa149d30
   i2c_rdwr_ioctl_data at: 0x7ffc4376a380
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x557eaa149d30 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 80 be 6e 80 be 6e 80 be 6e 80 be
(ddc_get_nontable_vcp_value    )           ddc_write_read_with_retry() returned DDCRC_ALL_RESPONSES_NULL(-3011): all tries returned DDC Null Message, response_packet_ptr=(nil)
(ddc_get_nontable_vcp_value    ) Done      Returning: Error_Info[DDCRC_ALL_RESPONSES_NULL in ddc_write_read_with_retry, causes: DDCRC_NULL_RESPONSE]. 
VCP code 0x5c (6 axis saturation: Cyan       ): Invalid response. status code=DDCRC_ALL_RESPONSES_NULL(-3011), Display_Handle[i2c-1: fd=3 @0x557eaa147750]

Getting data for non-table VCP code 0x5d - 6 axis saturation: Blue:
(ddc_get_nontable_vcp_value    ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x557eaa147750], Reading feature 0x5d
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x557eaa149d30
   i2c_rdwr_ioctl_data at: 0x7ffc4376a380
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x557eaa149d30 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 80 be 6e 80 be 6e 80 be 6e 80 be
(ddc_get_nontable_vcp_value    )           ddc_write_read_with_retry() returned DDCRC_ALL_RESPONSES_NULL(-3011): all tries returned DDC Null Message, response_packet_ptr=(nil)
(ddc_get_nontable_vcp_value    ) Done      Returning: Error_Info[DDCRC_ALL_RESPONSES_NULL in ddc_write_read_with_retry, causes: DDCRC_NULL_RESPONSE]. 
VCP code 0x5d (6 axis saturation: Blue       ): Invalid response. status code=DDCRC_ALL_RESPONSES_NULL(-3011), Display_Handle[i2c-1: fd=3 @0x557eaa147750]

Getting data for non-table VCP code 0x5e - 6 axis saturation: Magenta:
(ddc_get_nontable_vcp_value    ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x557eaa147750], Reading feature 0x5e
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x557eaa149d30
   i2c_rdwr_ioctl_data at: 0x7ffc4376a380
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x557eaa149d30 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 80 be 6e 80 be 6e 80 be 6e 80 be
(ddc_get_nontable_vcp_value    )           ddc_write_read_with_retry() returned DDCRC_ALL_RESPONSES_NULL(-3011): all tries returned DDC Null Message, response_packet_ptr=(nil)
(ddc_get_nontable_vcp_value    ) Done      Returning: Error_Info[DDCRC_ALL_RESPONSES_NULL in ddc_write_read_with_retry, causes: DDCRC_NULL_RESPONSE]. 
VCP code 0x5e (6 axis saturation: Magenta    ): Invalid response. status code=DDCRC_ALL_RESPONSES_NULL(-3011), Display_Handle[i2c-1: fd=3 @0x557eaa147750]

Getting data for non-table VCP code 0x6b - Backlight Level: White:
(ddc_get_nontable_vcp_value    ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x557eaa147750], Reading feature 0x6b
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x557eaa149d30
   i2c_rdwr_ioctl_data at: 0x7ffc4376a380
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x557eaa149d30 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 80 be 6e 80 be 6e 80 be 6e 80 be
(ddc_get_nontable_vcp_value    )           ddc_write_read_with_retry() returned DDCRC_ALL_RESPONSES_NULL(-3011): all tries returned DDC Null Message, response_packet_ptr=(nil)
(ddc_get_nontable_vcp_value    ) Done      Returning: Error_Info[DDCRC_ALL_RESPONSES_NULL in ddc_write_read_with_retry, causes: DDCRC_NULL_RESPONSE]. 
VCP code 0x6b (Backlight Level: White        ): Invalid response. status code=DDCRC_ALL_RESPONSES_NULL(-3011), Display_Handle[i2c-1: fd=3 @0x557eaa147750]

Getting data for non-table VCP code 0x6c - Video black level: Red:
(ddc_get_nontable_vcp_value    ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x557eaa147750], Reading feature 0x6c
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x557eaa149d30
   i2c_rdwr_ioctl_data at: 0x7ffc4376a380
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x557eaa149d30 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 88 02 00 6c 00 00 64 00 32 8e 6e
(ddc_get_nontable_vcp_value    )           Success reading feature x6c. *ppinterpreted_code=0x557eaa149da0
(ddc_get_nontable_vcp_value    )           mh=0x00, ml=0x64, sh=0x00, sl=0x32, max value=100, cur value=50
(ddc_get_nontable_vcp_value    ) Done      Returning: NULL. 
Raw value: opcode=0x6c, mh=0x00, ml=0x64, sh=0x00, sl=0x32, max_val=100 (0x0064), cur_val=50 (0x0032)
VCP code 0x6c (Video black level: Red        ): current value =    50, max value =   100

Getting data for non-table VCP code 0x6d - Backlight Level: Red:
(ddc_get_nontable_vcp_value    ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x557eaa147750], Reading feature 0x6d
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x557eaa149da0
   i2c_rdwr_ioctl_data at: 0x7ffc4376a380
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x557eaa149da0 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 80 be 6e 80 be 6e 80 be 6e 80 be
(ddc_get_nontable_vcp_value    )           ddc_write_read_with_retry() returned DDCRC_ALL_RESPONSES_NULL(-3011): all tries returned DDC Null Message, response_packet_ptr=(nil)
(ddc_get_nontable_vcp_value    ) Done      Returning: Error_Info[DDCRC_ALL_RESPONSES_NULL in ddc_write_read_with_retry, causes: DDCRC_NULL_RESPONSE]. 
VCP code 0x6d (Backlight Level: Red          ): Invalid response. status code=DDCRC_ALL_RESPONSES_NULL(-3011), Display_Handle[i2c-1: fd=3 @0x557eaa147750]

Getting data for non-table VCP code 0x6e - Video black level: Green:
(ddc_get_nontable_vcp_value    ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x557eaa147750], Reading feature 0x6e
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x557eaa149da0
   i2c_rdwr_ioctl_data at: 0x7ffc4376a380
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x557eaa149da0 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 88 02 00 6e 00 00 64 00 32 8c 6e
(ddc_get_nontable_vcp_value    )           Success reading feature x6e. *ppinterpreted_code=0x557eaa149d10
(ddc_get_nontable_vcp_value    )           mh=0x00, ml=0x64, sh=0x00, sl=0x32, max value=100, cur value=50
(ddc_get_nontable_vcp_value    ) Done      Returning: NULL. 
Raw value: opcode=0x6e, mh=0x00, ml=0x64, sh=0x00, sl=0x32, max_val=100 (0x0064), cur_val=50 (0x0032)
VCP code 0x6e (Video black level: Green      ): current value =    50, max value =   100

Getting data for non-table VCP code 0x6f - Backlight Level: Green:
(ddc_get_nontable_vcp_value    ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x557eaa147750], Reading feature 0x6f
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x557eaa149d10
   i2c_rdwr_ioctl_data at: 0x7ffc4376a380
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x557eaa149d10 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 80 be 6e 80 be 6e 80 be 6e 80 be
(ddc_get_nontable_vcp_value    )           ddc_write_read_with_retry() returned DDCRC_ALL_RESPONSES_NULL(-3011): all tries returned DDC Null Message, response_packet_ptr=(nil)
(ddc_get_nontable_vcp_value    ) Done      Returning: Error_Info[DDCRC_ALL_RESPONSES_NULL in ddc_write_read_with_retry, causes: DDCRC_NULL_RESPONSE]. 
VCP code 0x6f (Backlight Level: Green        ): Invalid response. status code=DDCRC_ALL_RESPONSES_NULL(-3011), Display_Handle[i2c-1: fd=3 @0x557eaa147750]

Getting data for non-table VCP code 0x70 - Video black level: Blue:
(ddc_get_nontable_vcp_value    ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x557eaa147750], Reading feature 0x70
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x557eaa149d10
   i2c_rdwr_ioctl_data at: 0x7ffc4376a380
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x557eaa149d10 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 88 02 00 70 00 00 64 00 32 92 6e
(ddc_get_nontable_vcp_value    )           Success reading feature x70. *ppinterpreted_code=0x557eaa149d30
(ddc_get_nontable_vcp_value    )           mh=0x00, ml=0x64, sh=0x00, sl=0x32, max value=100, cur value=50
(ddc_get_nontable_vcp_value    ) Done      Returning: NULL. 
Raw value: opcode=0x70, mh=0x00, ml=0x64, sh=0x00, sl=0x32, max_val=100 (0x0064), cur_val=50 (0x0032)
VCP code 0x70 (Video black level: Blue       ): current value =    50, max value =   100

Getting data for non-table VCP code 0x71 - Backlight Level: Blue:
(ddc_get_nontable_vcp_value    ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x557eaa147750], Reading feature 0x71
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x557eaa149d30
   i2c_rdwr_ioctl_data at: 0x7ffc4376a380
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x557eaa149d30 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 80 be 6e 80 be 6e 80 be 6e 80 be
(ddc_get_nontable_vcp_value    )           ddc_write_read_with_retry() returned DDCRC_ALL_RESPONSES_NULL(-3011): all tries returned DDC Null Message, response_packet_ptr=(nil)
(ddc_get_nontable_vcp_value    ) Done      Returning: Error_Info[DDCRC_ALL_RESPONSES_NULL in ddc_write_read_with_retry, causes: DDCRC_NULL_RESPONSE]. 
VCP code 0x71 (Backlight Level: Blue         ): Invalid response. status code=DDCRC_ALL_RESPONSES_NULL(-3011), Display_Handle[i2c-1: fd=3 @0x557eaa147750]

Getting data for non-table VCP code 0x72 - Gamma:
(ddc_get_nontable_vcp_value    ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x557eaa147750], Reading feature 0x72
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x557eaa149d30
   i2c_rdwr_ioctl_data at: 0x7ffc4376a380
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x557eaa149d30 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 80 be 6e 80 be 6e 80 be 6e 80 be
(ddc_get_nontable_vcp_value    )           ddc_write_read_with_retry() returned DDCRC_ALL_RESPONSES_NULL(-3011): all tries returned DDC Null Message, response_packet_ptr=(nil)
(ddc_get_nontable_vcp_value    ) Done      Returning: Error_Info[DDCRC_ALL_RESPONSES_NULL in ddc_write_read_with_retry, causes: DDCRC_NULL_RESPONSE]. 
VCP code 0x72 (Gamma                         ): Invalid response. status code=DDCRC_ALL_RESPONSES_NULL(-3011), Display_Handle[i2c-1: fd=3 @0x557eaa147750]

Getting data for non-table VCP code 0x8a - TV Color Saturation:
(ddc_get_nontable_vcp_value    ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x557eaa147750], Reading feature 0x8a
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x557eaa149d30
   i2c_rdwr_ioctl_data at: 0x7ffc4376a380
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x557eaa149d30 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 80 be 6e 80 be 6e 80 be 6e 80 be
(ddc_get_nontable_vcp_value    )           ddc_write_read_with_retry() returned DDCRC_ALL_RESPONSES_NULL(-3011): all tries returned DDC Null Message, response_packet_ptr=(nil)
(ddc_get_nontable_vcp_value    ) Done      Returning: Error_Info[DDCRC_ALL_RESPONSES_NULL in ddc_write_read_with_retry, causes: DDCRC_NULL_RESPONSE]. 
VCP code 0x8a (TV Color Saturation           ): Invalid response. status code=DDCRC_ALL_RESPONSES_NULL(-3011), Display_Handle[i2c-1: fd=3 @0x557eaa147750]

Getting data for non-table VCP code 0x90 - Hue:
(ddc_get_nontable_vcp_value    ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x557eaa147750], Reading feature 0x90
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x557eaa149d30
   i2c_rdwr_ioctl_data at: 0x7ffc4376a380
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x557eaa149d30 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 80 be 6e 80 be 6e 80 be 6e 80 be
(ddc_get_nontable_vcp_value    )           ddc_write_read_with_retry() returned DDCRC_ALL_RESPONSES_NULL(-3011): all tries returned DDC Null Message, response_packet_ptr=(nil)
(ddc_get_nontable_vcp_value    ) Done      Returning: Error_Info[DDCRC_ALL_RESPONSES_NULL in ddc_write_read_with_retry, causes: DDCRC_NULL_RESPONSE]. 
VCP code 0x90 (Hue                           ): Invalid response. status code=DDCRC_ALL_RESPONSES_NULL(-3011), Display_Handle[i2c-1: fd=3 @0x557eaa147750]

Getting data for non-table VCP code 0x9b - 6 axis hue control: Red:
(ddc_get_nontable_vcp_value    ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x557eaa147750], Reading feature 0x9b
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x557eaa149d30
   i2c_rdwr_ioctl_data at: 0x7ffc4376a380
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x557eaa149d30 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 80 be 6e 80 be 6e 80 be 6e 80 be
(ddc_get_nontable_vcp_value    )           ddc_write_read_with_retry() returned DDCRC_ALL_RESPONSES_NULL(-3011): all tries returned DDC Null Message, response_packet_ptr=(nil)
(ddc_get_nontable_vcp_value    ) Done      Returning: Error_Info[DDCRC_ALL_RESPONSES_NULL in ddc_write_read_with_retry, causes: DDCRC_NULL_RESPONSE]. 
VCP code 0x9b (6 axis hue control: Red       ): Invalid response. status code=DDCRC_ALL_RESPONSES_NULL(-3011), Display_Handle[i2c-1: fd=3 @0x557eaa147750]

Getting data for non-table VCP code 0x9c - 6 axis hue control: Yellow:
(ddc_get_nontable_vcp_value    ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x557eaa147750], Reading feature 0x9c
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x557eaa149d30
   i2c_rdwr_ioctl_data at: 0x7ffc4376a380
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x557eaa149d30 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 80 be 6e 80 be 6e 80 be 6e 80 be
(ddc_get_nontable_vcp_value    )           ddc_write_read_with_retry() returned DDCRC_ALL_RESPONSES_NULL(-3011): all tries returned DDC Null Message, response_packet_ptr=(nil)
(ddc_get_nontable_vcp_value    ) Done      Returning: Error_Info[DDCRC_ALL_RESPONSES_NULL in ddc_write_read_with_retry, causes: DDCRC_NULL_RESPONSE]. 
VCP code 0x9c (6 axis hue control: Yellow    ): Invalid response. status code=DDCRC_ALL_RESPONSES_NULL(-3011), Display_Handle[i2c-1: fd=3 @0x557eaa147750]

Getting data for non-table VCP code 0x9d - 6 axis hue control: Green:
(ddc_get_nontable_vcp_value    ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x557eaa147750], Reading feature 0x9d
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x557eaa149d30
   i2c_rdwr_ioctl_data at: 0x7ffc4376a380
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x557eaa149d30 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 80 be 6e 80 be 6e 80 be 6e 80 be
(ddc_get_nontable_vcp_value    )           ddc_write_read_with_retry() returned DDCRC_ALL_RESPONSES_NULL(-3011): all tries returned DDC Null Message, response_packet_ptr=(nil)
(ddc_get_nontable_vcp_value    ) Done      Returning: Error_Info[DDCRC_ALL_RESPONSES_NULL in ddc_write_read_with_retry, causes: DDCRC_NULL_RESPONSE]. 
VCP code 0x9d (6 axis hue control: Green     ): Invalid response. status code=DDCRC_ALL_RESPONSES_NULL(-3011), Display_Handle[i2c-1: fd=3 @0x557eaa147750]

Getting data for non-table VCP code 0x9e - 6 axis hue control: Cyan:
(ddc_get_nontable_vcp_value    ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x557eaa147750], Reading feature 0x9e
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x557eaa149d30
   i2c_rdwr_ioctl_data at: 0x7ffc4376a380
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x557eaa149d30 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 80 be 6e 80 be 6e 80 be 6e 80 be
(ddc_get_nontable_vcp_value    )           ddc_write_read_with_retry() returned DDCRC_ALL_RESPONSES_NULL(-3011): all tries returned DDC Null Message, response_packet_ptr=(nil)
(ddc_get_nontable_vcp_value    ) Done      Returning: Error_Info[DDCRC_ALL_RESPONSES_NULL in ddc_write_read_with_retry, causes: DDCRC_NULL_RESPONSE]. 
VCP code 0x9e (6 axis hue control: Cyan      ): Invalid response. status code=DDCRC_ALL_RESPONSES_NULL(-3011), Display_Handle[i2c-1: fd=3 @0x557eaa147750]

Getting data for non-table VCP code 0x9f - 6 axis hue control: Blue:
(ddc_get_nontable_vcp_value    ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x557eaa147750], Reading feature 0x9f
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x557eaa149d30
   i2c_rdwr_ioctl_data at: 0x7ffc4376a380
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x557eaa149d30 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 80 be 6e 80 be 6e 80 be 6e 80 be
(ddc_get_nontable_vcp_value    )           ddc_write_read_with_retry() returned DDCRC_ALL_RESPONSES_NULL(-3011): all tries returned DDC Null Message, response_packet_ptr=(nil)
(ddc_get_nontable_vcp_value    ) Done      Returning: Error_Info[DDCRC_ALL_RESPONSES_NULL in ddc_write_read_with_retry, causes: DDCRC_NULL_RESPONSE]. 
VCP code 0x9f (6 axis hue control: Blue      ): Invalid response. status code=DDCRC_ALL_RESPONSES_NULL(-3011), Display_Handle[i2c-1: fd=3 @0x557eaa147750]

Getting data for non-table VCP code 0xa0 - 6 axis hue control: Magenta:
(ddc_get_nontable_vcp_value    ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x557eaa147750], Reading feature 0xa0
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x557eaa149d30
   i2c_rdwr_ioctl_data at: 0x7ffc4376a380
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x557eaa149d30 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 80 be 6e 80 be 6e 80 be 6e 80 be
(ddc_get_nontable_vcp_value    )           ddc_write_read_with_retry() returned DDCRC_ALL_RESPONSES_NULL(-3011): all tries returned DDC Null Message, response_packet_ptr=(nil)
(ddc_get_nontable_vcp_value    ) Done      Returning: Error_Info[DDCRC_ALL_RESPONSES_NULL in ddc_write_read_with_retry, causes: DDCRC_NULL_RESPONSE]. 
VCP code 0xa0 (6 axis hue control: Magenta   ): Invalid response. status code=DDCRC_ALL_RESPONSES_NULL(-3011), Display_Handle[i2c-1: fd=3 @0x557eaa147750]

Getting data for non-table VCP code 0xdc - Display Mode:
(ddc_get_nontable_vcp_value    ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x557eaa147750], Reading feature 0xdc
(i2c_ioctl_reader1             ) Starting  fd=3, fn=/dev/i2c-1, slave_addr=0x37, bytect=12, readbuf=0x557eaa149d30
   i2c_rdwr_ioctl_data at: 0x7ffc4376a380
      nmsgs:    1
      i2c_msg[0]
         addr:     0x0037
         flags:    0x0001
         len:     0x000c (12)
         buf:     0x557eaa149d30 ->  00 00 00 00 00 00 00 00 00 00 00 00
(i2c_ioctl_reader1             ) Done      Returning: OK(0). readbuf: 6e 80 be 6e 80 be 6e 80 be 6e 80 be
(ddc_get_nontable_vcp_value    )           ddc_write_read_with_retry() returned DDCRC_ALL_RESPONSES_NULL(-3011): all tries returned DDC Null Message, response_packet_ptr=(nil)
(ddc_get_nontable_vcp_value    ) Done      Returning: Error_Info[DDCRC_ALL_RESPONSES_NULL in ddc_write_read_with_retry, causes: DDCRC_NULL_RESPONSE]. 
VCP code 0xdc (Display Mode                  ): Invalid response. status code=DDCRC_ALL_RESPONSES_NULL(-3011), Display_Handle[i2c-1: fd=3 @0x557eaa147750]
digitaltrails commented 1 year ago

The conundrum in this situation is how best to handle a Null Response. Does a particular Null Response indicate an unsupported feature or a monitor error. If the former, repeatedly retrying for the latter needlessly increases execution time and can drive up the sleep-multiplier calculated by dynamic sleep.

Could the optimisation of sleep interval be performed only when commands refer to basic-features, such as brightness and contrast, or known-to-be-supported features?

Known-to-be-supported features could be dynamically discovered by accumulating a list of successfully used features over time (as the user issues commands for them). This would build up a list of features eligible to participate in sleep interval optimisation. If it's true that a suitable sleep interval is common to all features, the known-list could determine the default sleep interval for the as yet untried commands, so all commands tried/untried would benefit from the current optimised value.

rockowitz commented 1 year ago

@digitaltrails While there are monitors that use the DDC Null Message to indicate an unsupported feature, it's uncommon. I've never seen it on one of my monitors, and I own many. I was very surprised that your Benq monitor exhibits the behaviour - I think of them as one of the better manufacturers in regards to the DDC/CI spec.

Putting in a large amount of code to accommodate the infrequent and non-spec-compliant case at the expense of the common case that is spec compliant does not make sense.

I have rewritten the ddc layer code for testing monitor communication ((functions check_how_unsupported_reported() and initial_checks_by_dh() in file ddc_displays.c) to make it more coherent while also optimizing the common case of spec compliance. I've also reworked the capabilities code, and tweaked the dsa algorithm to avoid Null Messages driving the sleep step unnecessarily high.

Have at it!

digitaltrails commented 1 year ago 
% rm -rf ~/.cache/ddcutil ; ~/bin/ddcutil --bus 1  capabilities
ddcutil: dsa2.c:866: dsa2_record_final: Assertion `( (rtable->cur_retry_loop_null_msg_ct > 0) && (null_adjustment_occurred) ) || ( !(rtable->cur_retry_loop_null_msg_ct > 0) && !(null_adjustment_occurred) )' failed.
[1]    6884 IOT instruction (core dumped)  ~/bin/ddcutil --bus 1 capabilities
digitaltrails commented 1 year ago

Also fails the same assertion for getvcp 10 if the monitor is connected but powered off. Does successfully do getvcp 10 if it's powered on.

A setvcp 10 100 completes without error no matter whether the power is on or off (which is true for ddcutil 1.4 as well, so it's OK). (In fact, in version 1.4, getvcp 10 returns a value even if the power off).

rockowitz commented 1 year ago

@digitaltrails The most recent commits should fix the assert problem you're seeing. If not, please run with --trcfunc dsa2_record_final --trcfunc adjust_sleep_time. Thanks.

digitaltrails commented 1 year ago

Still asserting:

% rm -rf ~/.cache/ddcutil ; src/ddcutil --trcfunc dsa2_record_final --trcfunc adjust_sleep_time  --bus 1  capabilities 2>&1 | tee assert.log
(adjust_sleep_time             ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x5626a51a3cd0], event_type=SE_WRITE_TO_READ, spec_sleep_time_millis=50, msg=(null)
(adjust_sleep_time             ) Done      spec_sleep_time_millis = 50, dsa_multiplier= 1.00, null_adjustment_millis=0, Returning: 50, *null_adjustment_added_loc-false
(adjust_sleep_time             ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x5626a51a3cd0], event_type=SE_POST_READ, spec_sleep_time_millis=50, msg=(null)
(adjust_sleep_time             ) Done      spec_sleep_time_millis = 50, dsa_multiplier= 1.00, null_adjustment_millis=0, Returning: 50, *null_adjustment_added_loc-false
(dsa2_record_final             ) Starting  busno=1, rtable=0x5626a51a3e60, ddcrc=OK(0): success, tries=1 dsa2_enabled=true, cur_loop_null_adjustment_occurred=false
(dsa2_record_final             )           cur_step=7, cur_retry_loop_step=7, cur_retry_loop_null_msg_ct=0, null_msg_max_step_for_success=-1
(dsa2_record_final             ) Done      busno=1, cur_step=7, cur_retry_loop_step=7, remaining_interval=3
(adjust_sleep_time             ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x5626a51a3cd0], event_type=SE_WRITE_TO_READ, spec_sleep_time_millis=50, msg=(null)
(adjust_sleep_time             ) Done      spec_sleep_time_millis = 50, dsa_multiplier= 1.00, null_adjustment_millis=0, Returning: 50, *null_adjustment_added_loc-false
(adjust_sleep_time             ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x5626a51a3cd0], event_type=SE_POST_READ, spec_sleep_time_millis=50, msg=(null)
(adjust_sleep_time             ) Done      spec_sleep_time_millis = 50, dsa_multiplier= 1.00, null_adjustment_millis=0, Returning: 50, *null_adjustment_added_loc-false
(adjust_sleep_time             ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x5626a51a3cd0], event_type=SE_WRITE_TO_READ, spec_sleep_time_millis=50, msg=(null)
(adjust_sleep_time             ) Done      spec_sleep_time_millis = 50, dsa_multiplier= 1.00, null_adjustment_millis=0, Returning: 50, *null_adjustment_added_loc-false
(adjust_sleep_time             ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x5626a51a3cd0], event_type=SE_POST_READ, spec_sleep_time_millis=50, msg=(null)
(adjust_sleep_time             ) Done      spec_sleep_time_millis = 50, dsa_multiplier= 1.00, null_adjustment_millis=0, Returning: 50, *null_adjustment_added_loc-false
(adjust_sleep_time             ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x5626a51a3cd0], event_type=SE_WRITE_TO_READ, spec_sleep_time_millis=50, msg=(null)
(adjust_sleep_time             )           Adding 25 milliseconds for 1 Null response(s), busno=1, event_type=SE_WRITE_TO_READ, adjusted_sleep_time=75 
(adjust_sleep_time             ) Done      spec_sleep_time_millis = 50, dsa_multiplier= 1.00, null_adjustment_millis=25, Returning: 75, *null_adjustment_added_loc-true
(adjust_sleep_time             ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x5626a51a3cd0], event_type=SE_POST_READ, spec_sleep_time_millis=50, msg=(null)
(adjust_sleep_time             )           Adding 25 milliseconds for 1 Null response(s), busno=1, event_type=SE_POST_READ, adjusted_sleep_time=75 
(adjust_sleep_time             ) Done      spec_sleep_time_millis = 50, dsa_multiplier= 1.00, null_adjustment_millis=25, Returning: 75, *null_adjustment_added_loc-true
(adjust_sleep_time             ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x5626a51a3cd0], event_type=SE_WRITE_TO_READ, spec_sleep_time_millis=50, msg=(null)
(adjust_sleep_time             )           Adding 100 milliseconds for 2 Null response(s), busno=1, event_type=SE_WRITE_TO_READ, adjusted_sleep_time=150 
(adjust_sleep_time             ) Done      spec_sleep_time_millis = 50, dsa_multiplier= 1.00, null_adjustment_millis=100, Returning: 150, *null_adjustment_added_loc-true
(adjust_sleep_time             ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x5626a51a3cd0], event_type=SE_POST_READ, spec_sleep_time_millis=50, msg=(null)
(adjust_sleep_time             )           Adding 100 milliseconds for 2 Null response(s), busno=1, event_type=SE_POST_READ, adjusted_sleep_time=150 
(adjust_sleep_time             ) Done      spec_sleep_time_millis = 50, dsa_multiplier= 1.00, null_adjustment_millis=100, Returning: 150, *null_adjustment_added_loc-true
(adjust_sleep_time             ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x5626a51a3cd0], event_type=SE_WRITE_TO_READ, spec_sleep_time_millis=50, msg=(null)
(adjust_sleep_time             )           Adding 200 milliseconds for 3 Null response(s), busno=1, event_type=SE_WRITE_TO_READ, adjusted_sleep_time=250 
(adjust_sleep_time             ) Done      spec_sleep_time_millis = 50, dsa_multiplier= 1.00, null_adjustment_millis=200, Returning: 250, *null_adjustment_added_loc-true
(adjust_sleep_time             ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x5626a51a3cd0], event_type=SE_POST_READ, spec_sleep_time_millis=50, msg=(null)
(adjust_sleep_time             )           Adding 200 milliseconds for 3 Null response(s), busno=1, event_type=SE_POST_READ, adjusted_sleep_time=250 
(adjust_sleep_time             ) Done      spec_sleep_time_millis = 50, dsa_multiplier= 1.00, null_adjustment_millis=200, Returning: 250, *null_adjustment_added_loc-true
(dsa2_record_final             ) Starting  busno=1, rtable=0x5626a51a3e60, ddcrc=DDCRC_NULL_RESPONSE(-3002): received DDC null response, tries=5 dsa2_enabled=true, cur_loop_null_adjustment_occurred=true
(dsa2_record_final             )           cur_step=7, cur_retry_loop_step=7, cur_retry_loop_null_msg_ct=4, null_msg_max_step_for_success=7
(dsa2_record_final             )           all tries failed. busno=1, New cur_step: 8
(dsa2_record_final             ) Done      busno=1, cur_step=8, cur_retry_loop_step=8, remaining_interval=3
(adjust_sleep_time             ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x5626a51a3cd0], event_type=SE_WRITE_TO_READ, spec_sleep_time_millis=50, msg=(null)
(adjust_sleep_time             ) Done      spec_sleep_time_millis = 50, dsa_multiplier= 1.30, null_adjustment_millis=0, Returning: 64, *null_adjustment_added_loc-false
(adjust_sleep_time             ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x5626a51a3cd0], event_type=SE_POST_READ, spec_sleep_time_millis=50, msg=(null)
(adjust_sleep_time             ) Done      spec_sleep_time_millis = 50, dsa_multiplier= 1.30, null_adjustment_millis=0, Returning: 64, *null_adjustment_added_loc-false
(dsa2_record_final             ) Starting  busno=1, rtable=0x5626a51a3e60, ddcrc=OK(0): success, tries=1 dsa2_enabled=true, cur_loop_null_adjustment_occurred=false
(dsa2_record_final             )           cur_step=8, cur_retry_loop_step=8, cur_retry_loop_null_msg_ct=0, null_msg_max_step_for_success=7
(dsa2_record_final             ) Done      busno=1, cur_step=8, cur_retry_loop_step=8, remaining_interval=3
(adjust_sleep_time             ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x5626a51a5c40], event_type=SE_PRE_MULTI_PART_READ, spec_sleep_time_millis=200, msg=Before reading capabilities
(adjust_sleep_time             ) Done      spec_sleep_time_millis = 200, dsa_multiplier= 1.30, null_adjustment_millis=0, Returning: 259, *null_adjustment_added_loc-false
(adjust_sleep_time             ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x5626a51a5c40], event_type=SE_WRITE_TO_READ, spec_sleep_time_millis=50, msg=(null)
(adjust_sleep_time             ) Done      spec_sleep_time_millis = 50, dsa_multiplier= 1.30, null_adjustment_millis=0, Returning: 64, *null_adjustment_added_loc-false
(adjust_sleep_time             ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x5626a51a5c40], event_type=SE_POST_READ, spec_sleep_time_millis=50, msg=(null)
(adjust_sleep_time             ) Done      spec_sleep_time_millis = 50, dsa_multiplier= 1.30, null_adjustment_millis=0, Returning: 64, *null_adjustment_added_loc-false
(dsa2_record_final             ) Starting  busno=1, rtable=0x5626a51a3e60, ddcrc=OK(0): success, tries=1 dsa2_enabled=true, cur_loop_null_adjustment_occurred=false
(dsa2_record_final             )           cur_step=8, cur_retry_loop_step=8, cur_retry_loop_null_msg_ct=0, null_msg_max_step_for_success=7
(dsa2_record_final             ) Done      busno=1, cur_step=8, cur_retry_loop_step=8, remaining_interval=3
(adjust_sleep_time             ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x5626a51a5c40], event_type=SE_POST_CAP_TABLE_SEGMENT, spec_sleep_time_millis=50, msg=Called from try_multi_part_read, request_subtype=0x00
(adjust_sleep_time             ) Done      spec_sleep_time_millis = 50, dsa_multiplier= 1.30, null_adjustment_millis=0, Returning: 64, *null_adjustment_added_loc-false
(adjust_sleep_time             ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x5626a51a5c40], event_type=SE_WRITE_TO_READ, spec_sleep_time_millis=50, msg=(null)
(adjust_sleep_time             ) Done      spec_sleep_time_millis = 50, dsa_multiplier= 1.30, null_adjustment_millis=0, Returning: 64, *null_adjustment_added_loc-false
(adjust_sleep_time             ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x5626a51a5c40], event_type=SE_POST_READ, spec_sleep_time_millis=50, msg=(null)
(adjust_sleep_time             ) Done      spec_sleep_time_millis = 50, dsa_multiplier= 1.30, null_adjustment_millis=0, Returning: 64, *null_adjustment_added_loc-false
(dsa2_record_final             ) Starting  busno=1, rtable=0x5626a51a3e60, ddcrc=OK(0): success, tries=1 dsa2_enabled=true, cur_loop_null_adjustment_occurred=false
(dsa2_record_final             )           cur_step=8, cur_retry_loop_step=8, cur_retry_loop_null_msg_ct=0, null_msg_max_step_for_success=7
(dsa2_record_final             ) Done      busno=1, cur_step=8, cur_retry_loop_step=8, remaining_interval=3
(adjust_sleep_time             ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x5626a51a5c40], event_type=SE_POST_CAP_TABLE_SEGMENT, spec_sleep_time_millis=50, msg=Called from try_multi_part_read, request_subtype=0x00
(adjust_sleep_time             ) Done      spec_sleep_time_millis = 50, dsa_multiplier= 1.30, null_adjustment_millis=0, Returning: 64, *null_adjustment_added_loc-false
(adjust_sleep_time             ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x5626a51a5c40], event_type=SE_WRITE_TO_READ, spec_sleep_time_millis=50, msg=(null)
(adjust_sleep_time             ) Done      spec_sleep_time_millis = 50, dsa_multiplier= 1.30, null_adjustment_millis=0, Returning: 64, *null_adjustment_added_loc-false
(adjust_sleep_time             ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x5626a51a5c40], event_type=SE_POST_READ, spec_sleep_time_millis=50, msg=(null)
(adjust_sleep_time             ) Done      spec_sleep_time_millis = 50, dsa_multiplier= 1.30, null_adjustment_millis=0, Returning: 64, *null_adjustment_added_loc-false
(dsa2_record_final             ) Starting  busno=1, rtable=0x5626a51a3e60, ddcrc=OK(0): success, tries=1 dsa2_enabled=true, cur_loop_null_adjustment_occurred=false
(dsa2_record_final             )           cur_step=8, cur_retry_loop_step=8, cur_retry_loop_null_msg_ct=0, null_msg_max_step_for_success=7
(dsa2_record_final             ) Done      busno=1, cur_step=7, cur_retry_loop_step=7, remaining_interval=3
(adjust_sleep_time             ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x5626a51a5c40], event_type=SE_POST_CAP_TABLE_SEGMENT, spec_sleep_time_millis=50, msg=Called from try_multi_part_read, request_subtype=0x00
(adjust_sleep_time             ) Done      spec_sleep_time_millis = 50, dsa_multiplier= 1.00, null_adjustment_millis=0, Returning: 50, *null_adjustment_added_loc-false
(adjust_sleep_time             ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x5626a51a5c40], event_type=SE_WRITE_TO_READ, spec_sleep_time_millis=50, msg=(null)
(adjust_sleep_time             ) Done      spec_sleep_time_millis = 50, dsa_multiplier= 1.00, null_adjustment_millis=0, Returning: 50, *null_adjustment_added_loc-false
(adjust_sleep_time             ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x5626a51a5c40], event_type=SE_POST_READ, spec_sleep_time_millis=50, msg=(null)
(adjust_sleep_time             ) Done      spec_sleep_time_millis = 50, dsa_multiplier= 1.00, null_adjustment_millis=0, Returning: 50, *null_adjustment_added_loc-false
(dsa2_record_final             ) Starting  busno=1, rtable=0x5626a51a3e60, ddcrc=OK(0): success, tries=1 dsa2_enabled=true, cur_loop_null_adjustment_occurred=false
(dsa2_record_final             )           cur_step=7, cur_retry_loop_step=7, cur_retry_loop_null_msg_ct=0, null_msg_max_step_for_success=7
(dsa2_record_final             ) Done      busno=1, cur_step=6, cur_retry_loop_step=6, remaining_interval=3
(adjust_sleep_time             ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x5626a51a5c40], event_type=SE_POST_CAP_TABLE_SEGMENT, spec_sleep_time_millis=50, msg=Called from try_multi_part_read, request_subtype=0x00
(adjust_sleep_time             ) Done      spec_sleep_time_millis = 50, dsa_multiplier= 0.70, null_adjustment_millis=0, Returning: 34, *null_adjustment_added_loc-false
(adjust_sleep_time             ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x5626a51a5c40], event_type=SE_WRITE_TO_READ, spec_sleep_time_millis=50, msg=(null)
(adjust_sleep_time             ) Done      spec_sleep_time_millis = 50, dsa_multiplier= 0.70, null_adjustment_millis=0, Returning: 34, *null_adjustment_added_loc-false
(adjust_sleep_time             ) Starting  dh=Display_Handle[i2c-1: fd=3 @0x5626a51a5c40], event_type=SE_POST_READ, spec_sleep_time_millis=50, msg=(null)
(adjust_sleep_time             ) Done      spec_sleep_time_millis = 50, dsa_multiplier= 0.70, null_adjustment_millis=0, Returning: 34, *null_adjustment_added_loc-false
(dsa2_record_final             ) Starting  busno=1, rtable=0x5626a51a3e60, ddcrc=DDCRC_NULL_RESPONSE(-3002): received DDC null response, tries=1 dsa2_enabled=true, cur_loop_null_adjustment_occurred=false
(dsa2_record_final             )           cur_step=6, cur_retry_loop_step=6, cur_retry_loop_null_msg_ct=1, null_msg_max_step_for_success=7
ddcutil: dsa2.c:873: dsa2_record_final: Assertion `( (rtable->cur_retry_loop_null_msg_ct > 0) && (cur_loop_null_adjustment_occurred) ) || ( !(rtable->cur_retry_loop_null_msg_ct > 0) && !(cur_loop_null_adjustment_occurred) )' failed.
rockowitz commented 1 year ago

@digitaltrails Another large set of changes in 2.0.0-dev for testing. It fixes the assertion error you noted, and also makes extensive changes to the dynamic sleep code.

I've added code that converts getvcp reply messages with the Unsupported Feature bit set to DDC Null Messages for simulating monitors that use the Null Message to indicate an unsupported feature, allowing me to test for this monitor behaviour. (FWIW, it's controlled by the godawfully named hidden option --force-null-msg-for-unsupported.) There's some more checking to better handle the Null Msg response in this ambiguous case. Hopefully it better handles your Benq.

Current relevant experimental options:

digitaltrails commented 1 year ago

I rescued the Beng, my sister-in-law was taking to the dump for recycling. Maybe recycling would have been for the best. But there has been some progress:

The capabilities command now works out of the box, nothing special required, and repeats fine too:

rm -rf ~/.cache/ddcutil; ~/bin/ddcutil --bus 1 capabilities; ~/bin/ddcutil --bus 1 capabilities

I also looped 50 setvcp/getvcp 10 commands, with no issues, no error messages, and nothing logged. Plus vdu_controls seems to working fine with it.

I've only been given a brief shake out, but it's looking good so far.