Skip to content

Commit

Permalink
ptp2: condense EOS OLCInfo related debug output
Browse files Browse the repository at this point in the history 
A full logging excerpt now looks like this
```
event 237: EOS event OLCInfoChanged (size 81, version 0x0b, mask 0x1fff)
    0x00: 49 00 00 00 ff 1f 00 00 01 00 01 01 a0 10 00 a0
    0x10: 01 01 50 20 2c 01 01 00 00 04 01 01 71 00 00 00
    0x20: 00 00 00 01 00 00 00 00 00 00 00 00 00 00 00 00
    0x30: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
    0x40: 00 00 00 00 00 00 00 00 00
event 237: olcmask 0x0001, 2 bytes: 01 00
event 238: olcmask 0x0002, 6 bytes: 01 01 a0 10 00 a0
event 239: olcmask 0x0004, 5 bytes: 01 01 50 20 2c
event 240: olcmask 0x0008, 4 bytes: 01 01 00 00
event 241: olcmask 0x0010, 4 bytes: 04 01 01 71
event 242: olcmask 0x0020, 6 bytes: 00 00 00 00 00 00
event 243: olcmask 0x0040, 8 bytes: 01 00 00 00 00 00 00 00
event 244: olcmask 0x0080, 4 bytes: 00 00 00 00
event 245: olcmask 0x0100, 6 bytes: 00 00 00 00 00 00
event 246: olcmask 0x0200, 5 bytes: 00 00 00 00 00
event 247: olcmask 0x0400, 5 bytes: 00 00 00 00 00
event 248: olcmask 0x0800, 9 bytes: 00 00 00 00 00 00 00 00 00
event 249: mask 0x1000 entry truncated (1 bytes), olcsizes table (8 bytes) wrong?
event 249: olcmask 0x1000, 1 bytes: 00
```

This allows for easy grepping of the log file. See comments for gained
insight into olcmask 0x0010 entries. The user visible strings info strings
of the UNKNOWN events have changed as well, e.g.:
```
UNKNOWN OLCInfo event 0x0010, 4 bytes: 04 02 06 2f
```
It also introduces a convenient ptp_bytes2str() function to render some
bytes into a string for immediate printing/copying.
  • Loading branch information
@axxel
axxel committed Sep 17, 2024
1 parent a26126a commit 7ef7a67
Show file tree
Hide file tree
Showing 3 changed files with 73 additions and 135 deletions.
193 changes: 58 additions & 135 deletions camlibs/ptp2/ptp-pack.c
View file
Original file line number Diff line number Diff line change
Expand Up @@ -34,6 +34,13 @@
#include <iconv.h>
#endif

#ifndef MAX
# define MAX(a, b) ((a) > (b) ? (a) : (b))
#endif
#ifndef MIN
# define MIN(a, b) ((a) < (b) ? (a) : (b))
#endif

static inline uint16_t
htod16p (PTPParams *params, uint16_t var)
{
Expand Down Expand Up @@ -2628,12 +2635,11 @@ static unsigned int olcsizes[0x15][13] = {
olcver = sizeof(olcsizes)/sizeof(olcsizes[0])-1;
}

ptp_debug (params, "event %d: OLC version is 0x%02x", i, olcver);
ptp_debug (params, "event %d: EOS event OLCInfoChanged (size %d)", i, size);
mask = size >= 14 ? dtoh16a(curdata+8+4) : 0;
ptp_debug (params, "event %d: EOS event OLCInfoChanged (size %d, version 0x%02x, mask 0x%04x)", i, size, olcver, mask);
if (size >= 0x8) { /* event info */
unsigned int k;
for (k=8;k<size;k++)
ptp_debug (params, " %d: %02x", k-8, curdata[k]);
for (unsigned k = 8; k < size; k += 16)
ptp_debug (params, " 0x%02x: %s", k-8, ptp_bytes2str(curdata + k, MIN(16, size-k), "%02x "));
}
if (size < 14) {
ce[i].type = PTP_CANON_EOS_CHANGES_TYPE_UNKNOWN;
Expand All @@ -2648,29 +2654,25 @@ static unsigned int olcsizes[0x15][13] = {
ptp_debug (params, "event %d: OLC unexpected size %d for blob len %d (not -4 nor -8)", i, size, len);
break;
}
mask = dtoh16a(curdata+8+4);
ptp_debug (params, "event %d: OLC mask 0x%04x length %d / data length %d", i, mask, len, len - 8);
curoff = 8+4+4;

for (j = 0; j <= 12 ; j++) {
unsigned int k;
unsigned int curmask = 1 << j;
unsigned int cursize = MIN(olcsizes[olcver][j], size - curoff);
if (curoff > size)
break;
if (!(mask & curmask))
continue;
if (curoff+olcsizes[olcver][j] > size) {
ptp_debug (params, "event %d: mask 0x%x size of olc entry %d exceeds total size %d", i, mask, curoff+olcsizes[olcver][j], size);
break;
}
ptp_debug (params, "event %d: olcmask 0x%04x", i, curmask);
for (k=0;k<olcsizes[olcver][j];k++) {
ptp_debug (params, " %d: %02x", k, curdata[curoff+k]);
if (olcsizes[olcver][j] != cursize) {
ptp_debug (params, "event %d: mask 0x%04x entry truncated (%d bytes), olcsizes table (%d bytes) wrong?",
i, curmask, cursize, olcsizes[olcver][j]);
}
ptp_debug (params, "event %d: olcmask 0x%04x, %d bytes: %s", i, curmask, cursize,
ptp_bytes2str(curdata + curoff, cursize, "%02x "));
switch (curmask) {
case CANON_EOS_OLC_BUTTON: {
ce[i].type = PTP_CANON_EOS_CHANGES_TYPE_UNKNOWN;
PTP_CANON_SET_INFO(ce[i], "Button %d", dtoh16a(curdata+curoff));
PTP_CANON_SET_INFO(ce[i], "Button %x", dtoh16a(curdata+curoff));
i++;
break;
}
Expand Down Expand Up @@ -2729,144 +2731,66 @@ static unsigned int olcsizes[0x15][13] = {
i++;
break;
}
case 0x0010: {
/* mask 0x0010: 4 bytes, 04 00 00 00 observed */
ce[i].type = PTP_CANON_EOS_CHANGES_TYPE_UNKNOWN;
PTP_CANON_SET_INFO(ce[i], "OLCInfo event 0x0010 content %02x%02x%02x%02x",
curdata[curoff],
curdata[curoff+1],
curdata[curoff+2],
curdata[curoff+3]
);
i++;
break;
}
case 0x0020: {
/* mask 0x0020: 6 bytes, 00 00 00 00 00 00 observed.
* This seems to be the self-timer record: when active,
* has the form of 00 00 01 00 XX XX, where the last two bytes
* stand for the number of seconds remaining until the shot */
ce[i].type = PTP_CANON_EOS_CHANGES_TYPE_UNKNOWN;
PTP_CANON_SET_INFO(ce[i], "OLCInfo event 0x0020 content %02x%02x%02x%02x%02x%02x",
curdata[curoff],
curdata[curoff+1],
curdata[curoff+2],
curdata[curoff+3],
curdata[curoff+4],
curdata[curoff+5]
);
i++;
break;
}
case 0x0040: {
int value = (signed char)curdata[curoff+2];
/* mask 0x0040: 7 bytes, 01 01 00 00 00 00 00 observed */
/* exposure indicator */
ce[i].type = PTP_CANON_EOS_CHANGES_TYPE_UNKNOWN;
PTP_CANON_SET_INFO(ce[i], "OLCInfo exposure indicator %d,%d,%d.%d (%02x%02x%02x%02x)",
curdata[curoff],
PTP_CANON_SET_INFO(ce[i], "OLCInfo exposure indicator %d,%d,%d.%d (%s)",
curdata[curoff+0],
curdata[curoff+1],
value/10,abs(value)%10,
curdata[curoff+3],
curdata[curoff+4],
curdata[curoff+5],
curdata[curoff+6]
value/10, abs(value)%10,
ptp_bytes2str(curdata + curoff + 3, olcsizes[olcver][j] - 3, "%02x ")
);
i++;
break;
}
case 0x0080: {
case 0x0010:
/* mask 0x0010: 4 bytes, 04 00 00 00 observed */
/* a full trigger capture cycle on the 5Ds with storing to card looks like this
(first column is the timestamp):
0.132778 4 bytes: 04 01 01 71 after EOS_SetRequestOLCInfoGroup
0.246439 4 bytes: 04 02 01 70 after EOS_RemoteReleaseOn (0x2,0x0)
1.291545 4 bytes: 04 02 01 71 after first "non-busy" EOS_SetDevicePropValueEx
2.251470 4 bytes: 04 01 01 71 after object info added
and on the R8 it looks like this (after the same events):
0.357627 4 bytes: 04 01 06 2f
0.436084 4 bytes: 04 02 06 2e
0.942222 4 bytes: 04 02 06 2f
0.942969 4 bytes: 04 01 06 2f
This suggests that the very last bit indicates the readiness to process commands
and the second byte may be related to accessing storage.
*/
case 0x0020:
/* mask 0x0020: 6 bytes, 00 00 00 00 00 00 observed.
* This seems to be the self-timer record: when active,
* has the form of 00 00 01 00 XX XX, where the last two bytes
* stand for the number of seconds remaining until the shot */
case 0x0080:
/* mask 0x0080: 4 bytes, 00 00 00 00 observed */
ce[i].type = PTP_CANON_EOS_CHANGES_TYPE_UNKNOWN;
PTP_CANON_SET_INFO(ce[i], "OLCInfo event 0x0080 content %02x%02x%02x%02x",
curdata[curoff],
curdata[curoff+1],
curdata[curoff+2],
curdata[curoff+3]
);
i++;
break;
}
case 0x0100: {
/* mask 0x0100: 6 bytes, 00 00 00 00 00 00 (before focus) and 00 00 00 00 01 00 (on focus) observed */
ce[i].type = PTP_CANON_EOS_CHANGES_TYPE_FOCUSINFO;
PTP_CANON_SET_INFO(ce[i], "%02x%02x%02x%02x%02x%02x",
curdata[curoff],
curdata[curoff+1],
curdata[curoff+2],
curdata[curoff+3],
curdata[curoff+4],
curdata[curoff+5]
);
i++;
break;
}
case 0x0200: {
case 0x0100:
/* mask 0x0100: 6 bytes, 00 00 00 00 00 00 (before focus) and
* 00 00 00 00 01 00 (on focus) observed */
case 0x0200:
/* mask 0x0200: 7 bytes, 00 00 00 00 00 00 00 observed */
ce[i].type = PTP_CANON_EOS_CHANGES_TYPE_FOCUSMASK;
PTP_CANON_SET_INFO(ce[i], "%02x%02x%02x%02x%02x%02x%02x",
curdata[curoff],
curdata[curoff+1],
curdata[curoff+2],
curdata[curoff+3],
curdata[curoff+4],
curdata[curoff+5],
curdata[curoff+6]
);
i++;
break;
}
case 0x0400: {
case 0x0400:
/* mask 0x0400: 7 bytes, 00 00 00 00 00 00 00 observed */
ce[i].type = PTP_CANON_EOS_CHANGES_TYPE_UNKNOWN;
PTP_CANON_SET_INFO(ce[i], "OLCInfo event 0x0400 content %02x%02x%02x%02x%02x%02x%02x",
curdata[curoff],
curdata[curoff+1],
curdata[curoff+2],
curdata[curoff+3],
curdata[curoff+4],
curdata[curoff+5],
curdata[curoff+6]
);
i++;
break;
}
case 0x0800: {
/* mask 0x0800: 8 bytes, 00 00 00 00 00 00 00 00 and 19 01 00 00 00 00 00 00 and others observed */
/* might be mask of focus points selected */
ce[i].type = PTP_CANON_EOS_CHANGES_TYPE_UNKNOWN;
PTP_CANON_SET_INFO(ce[i], "OLCInfo event 0x0800 content %02x%02x%02x%02x%02x%02x%02x%02x",
curdata[curoff],
curdata[curoff+1],
curdata[curoff+2],
curdata[curoff+3],
curdata[curoff+4],
curdata[curoff+5],
curdata[curoff+6],
curdata[curoff+7]
);
i++;
break;
}
case 0x1000: {
case 0x0800:
/* mask 0x0800: 8 bytes, 00 00 00 00 00 00 00 00 and 19 01 00 00 00 00 00 00 and others observed
* might be mask of focus points selected */
case 0x1000:
/* mask 0x1000: 1 byte, 00 observed */
/* mask 0x1000: 8 byte too on 5ds, type 11 (has shuttercount inside) */
/* mask 0x1000: 8 byte too on 5ds, version 0xb (has shuttercount inside)
axxel's 5Ds only contains 1 byte!?! */
default:
ce[i].type = PTP_CANON_EOS_CHANGES_TYPE_UNKNOWN;
PTP_CANON_SET_INFO(ce[i], "OLCInfo event 0x1000 content %02x",
curdata[curoff]
);
PTP_CANON_SET_INFO(ce[i], "OLCInfo event 0x%04x, %d bytes: %s", curmask, olcsizes[olcver][j],
ptp_bytes2str(curdata + curoff, olcsizes[olcver][j], "%02x "));
i++;
break;
}
default: {
break;
}
}
curoff += olcsizes[olcver][j];
}
/* handle more masks */
ce[i].type = PTP_CANON_EOS_CHANGES_TYPE_UNKNOWN;
PTP_CANON_SET_INFO(ce[i], "OLCInfo event mask=%x", mask);
break;
}
case PTP_EC_CANON_EOS_CameraStatusChanged:
Expand Down Expand Up @@ -2923,7 +2847,6 @@ static unsigned int olcsizes[0x15][13] = {
XX(RequestCancelTransfer)
XX(RequestObjectTransferDT)
XX(RequestCancelTransferDT)
XX(BulbExposureTime)
XX(RecordingTime)
XX(RequestObjectTransferTS)
XX(AfResult)
Expand Down
14 changes: 14 additions & 0 deletions camlibs/ptp2/ptp.c
View file
Original file line number Diff line number Diff line change
Expand Up @@ -172,6 +172,20 @@ ptp_error (PTPParams *params, const char *format, ...)
va_end (args);
}

/* Helper function to quickly render some bytes into a static string
* buffer for immediate copying/snprintf-ing. Parameter fmt is the
* format string used for each byte, e.g. "%02x ". */
const char*
ptp_bytes2str(const uint8_t* data, int data_size, const char* fmt)
{
static char line[16 * 3 + 1];
int pos = 0;
for (int i = 0; i < data_size && pos < (int)sizeof(line); ++i) {
pos += snprintf(line + pos, sizeof(line) - pos, fmt, data[i]);
}
return line;
}

/* Pack / unpack functions */

#include "ptp-pack.c"
Expand Down
1 change: 1 addition & 0 deletions camlibs/ptp2/ptp.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -4823,6 +4823,7 @@ void ptp_free_object (PTPObject *oi);
const char *ptp_strerror (uint16_t ret, uint16_t vendor);
void ptp_debug (PTPParams *params, const char *format, ...);
void ptp_error (PTPParams *params, const char *format, ...);
const char* ptp_bytes2str(const uint8_t* data, int data_size, const char* fmt);


const char* ptp_get_property_description(PTPParams* params, uint32_t dpc);
Expand Down

0 comments on commit 7ef7a67

Please sign in to comment.