Author Topic: EOSM Shutter-Bug reboot  (Read 1916 times)

dfort

  • Developer
  • Hero Member
  • *****
  • Posts: 2788
Re: EOSM Shutter-Bug reboot
« Reply #50 on: April 01, 2018, 10:17:36 PM »
Yes, the timing changes slightly and sometimes the order also changes. I thought I had something significant this morning when the log that exhibited the shutter-bug showed that the mpu_send event that sets what we found out was PROP_LV_PROHIBIT_OUTPUT was skipped. I counted lines and figured it was the 53rd mpu_send call so that's the one I delayed and it worked on both the SanDisk card hacked to show the shutter-bug as well as the Lexar card that shows the shutter-bug. However, it wasn't consistant over several camera restarts.

https://www.dropbox.com/sh/nskqhfj1am797et/AAA11okP24-gPpJwEHVGSVLAa?dl=0
5D3.* 7D.* 700D.115 EOSM.* EOSM2.103 500D.112

dfort

  • Developer
  • Hero Member
  • *****
  • Posts: 2788
Re: EOSM Shutter-Bug reboot
« Reply #51 on: April 02, 2018, 08:01:15 AM »
Yet more testing. I wasn't getting anything worth posting with the SanDisk card hacked to show the shutter-bug so I grabbed the Lexar card that reliably shows the shutter-bug. This morning it did start up without the shutter-bug by delaying mpu_send call 53 by 280ms so how about trying calls 2-60 one at a time? In addition, 280ms is heavy handed so I went with the expected 70ms delay. Here's how it went:

Code: [Select]
call  3 delay 70 - worked but not repeatable
call 26 delay 70 - worked but not repeatable
call 28 delay 70 - worked log saved not repeatable
call 34 delay 70 - worked but not repeatable
call 42 delay 70 - worked but not repeatable
call 43 delay 70 - worked but not repeatable
call 50 delay 70 - worked but not repeatable
call 51 delay 70 - worked but not repeatable

Then I tried doing "else if" statements that covered all of the calls that worked but that didn't work at all.

Finally, I tried the trick of pressing the ON/OFF button quickly twice as soon as something comes on the LiveView screen and was able to get it to start up without the shutter-bug. Yeah, sounds weird but that's one of the workarounds that was reported on the Bitbucket issue page. Now that I think of it, that workaround is probably doing the delay only it is something that is repeatable--thought not very practical. Saved that log in the same Dropbox folder listed on my previous posts from today. Maybe there are some important clues in these logs?

Looks like this is the section that gets a big delay with the ON/OFF/ON workaround:

Code: [Select]
0.329.426  **INT-36h*:0001dedc:00:00: *** mpu_recv(06 05 01 8a 00 00)                               ; PROP_SW2_MOVIE_START
0.330.038     PropMgr:0000393c:00:00: *** mpu_send(0a 08 01 3b ff ff 00 00 00)                      ; PROP_USBDEVICE_CONNECT
0.331.657     PropMgr:0000393c:00:00: *** mpu_send(0a 08 01 3b ff 00 00 00 00)                      ; PROP_USBDEVICE_CONNECT
0.707.970  **INT-36h*:0001dedc:00:00: *** mpu_recv(06 05 03 5d 94 00)                               ; PROP 80030062
0.708.158  **INT-36h*:0001dedc:00:00: *** mpu_recv(06 05 03 38 96 00)                               ; PROP 80030035
0.788.374     PropMgr:0000393c:00:00: *** mpu_send(08 07 01 2a 1c e4 00 00)                         ; PROP_CARD2_FILE_NUMBER
0.789.574     PropMgr:0000393c:00:00: *** mpu_send(08 07 01 2a 1c e4 00 00)                         ; PROP_CARD2_FILE_NUMBER

[EDIT] Another false assumption. Turns out that there is always a delay of about 300-400ms at mpu_send event 37 whether or not the ON/OFF/ON workaround is used.
5D3.* 7D.* 700D.115 EOSM.* EOSM2.103 500D.112

dfort

  • Developer
  • Hero Member
  • *****
  • Posts: 2788
Re: EOSM Shutter-Bug reboot
« Reply #52 on: April 02, 2018, 07:08:44 PM »
Whoopi -- more logs:

https://www.dropbox.com/sh/91yck4i9cn1fbi9/AACUnEJ-X_ERgXJCkLO7AOi0a?dl=0

Since the ON/OFF/ON workaround is something that consistently kills the shutter-bug, I thought it might be interesting to see what makes it tick. Maybe figure out where to put a delay?

Process - make 5 runs each of the ON/OFF/ON workaround with the Lexar (shutter-bug) card and the SanDisk (no shutter-bug) card. The SanDisk card has the delay on the first mpu_send event to induce the shutter-bug while the Lexar card does not (not needed). Also saved are reference logs showing what happens without the ON/OFF/ON workaround. One last log is the SanDisk card started up normally without the shutter-bug hack as a "gold standard" reference.

One of the things I noticed after annotating the logs is that all of the ON/OFF/ON workaround logs show PROP_ACTIVE_SWEEP_STATUS. This is the sensor cleaning on shutdown event. This makes sense because the camera is shutdown and quickly restarted. I also tried disabling sensor cleaning and the PROP_ACTIVE_SWEEP_STATUS doesn't show up on the log but it has no effect on the shutter-bug or the effectiveness of the ON/OFF/ON workaround so I won't go any further down that road.

Interesting is that even though the power is shutdown then quickly turned back on it never goes back to the "Init group" and doesn't repeat most of the early mpu_send calls.

These do not repeat after ON/OFF/ON is triggered:
Code: [Select]
   ; Init group
   ; Complete WaitID = Mode group
   ; Complete WaitID = PROP 8003006F
   ; PROP 8003005E
   ; PROP 80030008
   ; PROP_SAVE_MODE

But wait--there's more. As long as I was logging workarounds I made one last annotated log of the lens twist workaround only this time with the trimmed down io_trace_full build on the Lexar card. I keep thinking that one way to kill the shutter-bug is to re-initialize the lens properties at some point in the startup process and maybe this log will show how that can be done?
5D3.* 7D.* 700D.115 EOSM.* EOSM2.103 500D.112

dfort

  • Developer
  • Hero Member
  • *****
  • Posts: 2788
Re: EOSM Shutter-Bug reboot
« Reply #53 on: April 05, 2018, 06:14:27 PM »
Let's try some overclocking: sd_uhs.mo (to be loaded on top of crop_rec_4k branch). Got the idea after looking into the EOS M shutter bug and understanding how clocks work - to some extent.

Cool - good to know something good has emerged from this.

First thing I tried was to see if overclocking cures the shutter-bug. Nope.

Found something interesting when untwisting the lens--which always clears up the shutter-bug. PROP_LENS (0x80030011) temporarily changes value to zero.

Code: [Select]
8CBEF>     PtpDps:ff292d3c:33:01: ptpPropertyChangeEvent[80030011][1f][0][0]
8CC2E>     PtpDps:ff2838c8:32:01: GetConnectSessionFirst end[0][3]
8CC5F>     PtpDps:ff29e648:33:01: PROP:0x80030011,0

Note that this is not the same as starting the camera without a lens attached:

Code: [Select]
9CC43>     PtpDps:ff292d3c:33:01: ptpPropertyChangeEvent[80030011][1f][10542c01][0]
9CC7E>     PtpDps:ff2838c8:32:01: GetConnectSessionFirst end[0][3]
9CCA2>     PtpDps:ff29e648:33:01: PROP:0x80030011,10542c01

Maybe there's something here? Do a prop_request_change on PROP_LENS to "0" hoping it doesn't brick the camera so next time the lens is polled it will reload the properties and kill the shutter-bug? Maybe this is a read only property and prop_request_change won't work? Never tried it--sounds sort of scary.

[EDIT] Never mind. Looks like that property is read only.
5D3.* 7D.* 700D.115 EOSM.* EOSM2.103 500D.112