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

dfort

  • Developer
  • Hero Member
  • *****
  • Posts: 3146
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.206 700D.115 EOSM.203

dfort

  • Developer
  • Hero Member
  • *****
  • Posts: 3146
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.206 700D.115 EOSM.203

dfort

  • Developer
  • Hero Member
  • *****
  • Posts: 3146
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.206 700D.115 EOSM.203

dfort

  • Developer
  • Hero Member
  • *****
  • Posts: 3146
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.206 700D.115 EOSM.203

dfort

  • Developer
  • Hero Member
  • *****
  • Posts: 3146
Re: EOSM Shutter-Bug reboot
« Reply #54 on: May 01, 2018, 09:39:20 PM »
Picked up a couple of super cheap sd cards at the local electronics swap meet and turns out that they aren't affected by the shutter-bug. These cards still had the GPS maps on them but after formatting and installing ML on them, they worked fine. I didn't run the benchmark speed test on them but they are very slow cards.



More information about card sizes and formatting:

https://www.sdcard.org/developers/overview/capacity/index.html

So far all SD standard cards I've tested don't show the shutter-bug, the SanDisk Extreme 32GB which is a SDHC standard card is fine most of the time and no SDXC standard card I've tested is immune from the bug.

Yeah, I'd like to resolve the shutter-bug once and for all but sometimes you just need to let something rest for a while.
5D3.* 7D.206 700D.115 EOSM.203

Danne

  • Hero Member
  • *****
  • Posts: 4442
Re: EOSM Shutter-Bug reboot
« Reply #55 on: May 01, 2018, 10:09:49 PM »
sd_uhs? :) :)

a1ex

  • Administrator
  • Hero Member
  • *****
  • Posts: 11721
  • 5D Mark Free
Re: EOSM Shutter-Bug reboot
« Reply #56 on: May 01, 2018, 10:10:54 PM »
The file I/O routines have some trouble with large filesystems - for example, the portable ROM dumper works best on a 256MB filesystem, but a 16GB card is already too large for it. The issue can be reproduced in QEMU, without loading any code from the card first: from the FROMUTILITY menu, jump to "Init SD" (address printed by portable ROM dumper), then to the "Open file for write" function (address printed there as well) and use a GDB breakpoint to supply some parameters (drive, file name, address, size). Maybe these bootloader I/O functions are just very slow with large cards?

During normal execution (with boot flag disabled), there's no SD card access made by the bootloader. With boot flag enabled, the bootloader has to mount the filesystem in order to load autoexec.bin from it.

If you copy the 256MB QEMU image with dd to the large card, and run ML from it, does it still show the shutter bug?

(I've suggested a similar test earlier, but the raw card speed can also influence the result; this should no longer be the case with a 256MB filesystem)

@Danne: we are talking about bootloader, before ML code is loaded and has a chance to run.

Danne

  • Hero Member
  • *****
  • Posts: 4442
Re: EOSM Shutter-Bug reboot
« Reply #57 on: May 01, 2018, 10:20:04 PM »
Yes, following this thread always, what I can understand. Nasty bug...

dfort

  • Developer
  • Hero Member
  • *****
  • Posts: 3146
Re: EOSM Shutter-Bug reboot
« Reply #58 on: May 02, 2018, 03:30:51 AM »
If you copy the 256MB QEMU image with dd to the large card, and run ML from it, does it still show the shutter bug?

No it doesn't. I think we might have played around with this before but it is worth revisiting. I took a 64GB card that quite reliably shows the shutter bug and copied the QEMU sd.img to it this way:

Code: [Select]
sudo dd if=~/qemu-eos/sd.img of=/dev/disk3
Password:
506880+0 records in
506880+0 records out
259522560 bytes transferred in 245.820091 secs (1055742 bytes/sec)

Viola! No shutter-bug. Of course now that 64GB card is only 256MB. Formatted card in camera and it is back to 64GB and the shutter-bug is back too.
5D3.* 7D.206 700D.115 EOSM.203

Licaon_Kter

  • Hero Member
  • *****
  • Posts: 519
  • M
Re: EOSM Shutter-Bug reboot
« Reply #59 on: May 18, 2018, 10:52:52 AM »
Keeping an eye on this too

ArcziPL

  • Freshman
  • **
  • Posts: 68
Re: EOSM Shutter-Bug reboot
« Reply #60 on: May 18, 2018, 12:51:07 PM »
I took a 64GB card that quite reliably shows the shutter bug and copied the QEMU sd.img to it
Does the camera format the card using another filesystem than the QEMU image uses?
70D.112 | 700D.115 | M.202 | 450D.110

dfort

  • Developer
  • Hero Member
  • *****
  • Posts: 3146
Re: EOSM Shutter-Bug reboot
« Reply #61 on: May 18, 2018, 10:26:24 PM »
The camera formats the card differently depending on what card you're using, SD/SDHC/SDXC. According to the Mac OS disk utility the QEMU sd.img file is formatted as MS-DOS (FAT16) which is used for SD standard cards. Note that SD standard (2GB and less) do not show the shuter-bug. More information here:

https://www.sdcard.org/developers/overview/capacity/index.html
5D3.* 7D.206 700D.115 EOSM.203

a1ex

  • Administrator
  • Hero Member
  • *****
  • Posts: 11721
  • 5D Mark Free
Re: EOSM Shutter-Bug reboot
« Reply #62 on: May 19, 2018, 10:32:12 AM »
Current hypothesis: what makes a difference is the time needed to index the contents of that filesystem (or whatever Canon bootloader does in order to load autoexec.bin). That time might be smaller with a FAT32 filesystem, as it's less complex. That time may also depend on whether the card contains photos or not, or maybe just other files in the root directory.

The 256MB image used with QEMU makes a difference because the bootloader no longer looks at all the unused space on the card (a process that takes a while on larger cards). If you are wondering where that magic size comes from -- one of my cards has that size, so the initial QEMU image was a dd image of that card. However, now that we can format the virtual card directly from the emulated camera, you can use any other size (dd if=/dev/zero of=sd.img count=whatever). The largest I've tested in the emulator is a 64GB image copied from a real card, saved as qcow2.

You can format the 64GB card as FAT32 in the camera with the experimental card_fmt module. Maybe it helps with some cards (though I remember copying the FAT32 filesystem from a 32GB card didn't help...)

dfort

  • Developer
  • Hero Member
  • *****
  • Posts: 3146
Re: EOSM Shutter-Bug reboot
« Reply #63 on: July 27, 2018, 08:36:20 PM »
Wondering if anybody experienced the shutter-bug with the EF-M 28mm IS Macro lens?



Just curious if what is causing the bug is related to the image stabilization or if it only happens on zoom lenses. All EF-M IS lenses up until now were zoom lenses--in fact all EF-M zoom lenses have IS. This macro lens is the first prime lens that I'm aware of that has image stabilization.
5D3.* 7D.206 700D.115 EOSM.203

Kathode-Ray

  • New to the forum
  • *
  • Posts: 29
Re: EOSM Shutter-Bug reboot
« Reply #64 on: October 18, 2018, 12:17:17 PM »
I can confirm that with the 28mm Macro lens the shutter-bug is also present.

I used the crop_rec_4k_mlv_lite_snd.2018Apr03.EOSM202 build. As soon as I unlock the lens and turn it to the other shooting mode (normal to super macro or v.v.), the bug is gone.

Switching off the camera for few minutes usually brings it back, but sometimes it also decides to stay away, and then I have to pull the battery to get the bug back. I tried to reproduce it reliably for two hours but no luck...
6DmkII | M50 | M || AT-X 16-28 | 24-70 2.8 VC | 24-105 4.0L | 70-200 4.0L IS || 35 2.0 IS | 45 1.8 VC | 100 2.0 | 135 2.0 || 11-22 | 18-55 | 55-200 | 22 | 28 Macro || Metz 58 AF-2 | Røde Videomic Pro

dfort

  • Developer
  • Hero Member
  • *****
  • Posts: 3146
Re: EOSM Shutter-Bug reboot
« Reply #65 on: October 18, 2018, 06:17:08 PM »
v.v.?

Ok--I was betting that the shutter-bug would show up with this lens.

Looking at all of the available EF-M lenses from Canon, only the 22mm prime lens doesn't show the shutter-bug. It is also the only non Image Stabilization (IS) lens from Canon. Other manufacturers like Tamron also make EF-M lenses, also with their form of image stabilization and also show the shutter-bug.

@Kathode-Ray - you should be able to reproduce the bug with any SD card 64GB or larger, any ML build and starting the camera with the lens in the shooting position. It only affects still images so put the camera in photo mode and try shooting a still. Put the lens in the collapsed position then back to the shooting position and the shutter-bug should disappear. There's no need to pull the battery, simply restarting the camera with the lens in the shooting position will bring it back.
5D3.* 7D.206 700D.115 EOSM.203