suba threading bug (was Re: 3D scanner with multiple IXUS160 cameras) - page 4 - General Discussion and Assistance - CHDK Forum

suba threading bug (was Re: 3D scanner with multiple IXUS160 cameras)

  • 77 Replies
  • 22704 Views
*

Offline philmoz

  • *****
  • 3450
    • Photos
Re: suba threading bug (was Re: 3D scanner with multiple IXUS160 cameras)
« Reply #30 on: 04 / October / 2017, 16:52:28 »
Advertisements
However, it is currently unclear, to me, whether the usbhub reorganisation is solely responsible for the improved results or whether that and the smaller footprint of CHDK_LIGHT was responsible.


As reyalp said, it's unlikely to be memory. Most of the stuff removed from 'CHDK_LIGHT' is modules and games which don't use any memory until they are loaded. It's also an old version of CHDK and isn't going to get updated or supported unless David does it (don't hold your breath).


Phil.
CHDK ports:
  sx30is (1.00c, 1.00h, 1.00l, 1.00n & 1.00p)
  g12 (1.00c, 1.00e, 1.00f & 1.00g)
  sx130is (1.01d & 1.01f)
  ixus310hs (1.00a & 1.01a)
  sx40hs (1.00d, 1.00g & 1.00i)
  g1x (1.00e, 1.00f & 1.00g)
  g5x (1.00c, 1.01a, 1.01b)
  g7x2 (1.01a, 1.01b, 1.10b)

Re: suba threading bug (was Re: 3D scanner with multiple IXUS160 cameras)
« Reply #31 on: 04 / October / 2017, 17:31:04 »
IMO this is unlikely for several reasons:

That now makes sense - thanks.

FWIW, I'm very unlikely to spend any of my time debugging CHDK_LIGHT or supporting it in any other way.

FWIW:
CHDK_LIGHT does not need any debugging - I didn't request you to support it in any way. Without depth of knowledge, I simply wanted to see if a smaller version of CHDK made any difference.

Re: suba threading bug (was Re: 3D scanner with multiple IXUS160 cameras)
« Reply #32 on: 05 / October / 2017, 11:28:34 »
With Phil's latest build (thankfully uploaded to all cameras using existing chdkptp):

Test was:

lock_ptp_comms
switch to record

repeat x 8

preshoot->usb_sync_shoot->open 5V switch->download to PC->delete camera image

was successful.

On the 9th cycle, at download an I/O error occurred and cam2 made the usb disconnect sound.

romlog attached (date is as per camera).

Final section of cli trace:
Code: [Select]
___> !return mc:cmdwait('preshoot')
preshoot
=true,{
 [1]={
  failed=false,
  done=true,
  status={
   status=true,
   cmd="preshoot",
  },
 },
 [2]={
  failed=false,
  done=true,
  status={
   status=true,
   cmd="preshoot",
  },
 },
 [3]={
  failed=false,
  done=true,
  status={
   status=true,
   cmd="preshoot",
  },
 },
 [4]={
  failed=false,
  done=true,
  status={
   status=true,
   cmd="preshoot",
  },
 },
 [5]={
  failed=false,
  done=true,
  status={
   status=true,
   cmd="preshoot",
  },
 },
 [6]={
  failed=false,
  done=true,
  status={
   status=true,
   cmd="preshoot",
  },
 },
 [7]={
  failed=false,
  done=true,
  status={
   status=true,
   cmd="preshoot",
  },
 },
 [8]={
  failed=false,
  done=true,
  status={
   status=true,
   cmd="preshoot",
  },
 },
 [9]={
  failed=false,
  done=true,
  status={
   status=true,
   cmd="preshoot",
  },
 },
 [10]={
  failed=false,
  done=true,
  status={
   status=true,
   cmd="preshoot",
  },
 },
 [11]={
  failed=false,
  done=true,
  status={
   status=true,
   cmd="preshoot",
  },
 },
 [12]={
  failed=false,
  done=true,
  status={
   status=true,
   cmd="preshoot",
  },
 },
 [13]={
  failed=false,
  done=true,
  status={
   status=true,
   cmd="preshoot",
  },
 },
 [14]={
  failed=false,
  done=true,
  status={
   status=true,
   cmd="preshoot",
  },
 },
 [15]={
  failed=false,
  done=true,
  status={
   status=true,
   cmd="preshoot",
  },
 },
 [16]={
  failed=false,
  done=true,
  status={
   status=true,
   cmd="preshoot",
  },
 },
}
___> !return mc:cmdwait('usb_sync_wait')
usb_sync_wait
=true,{
 [1]={
  failed=false,
  done=true,
  status={
   status=true,
   cmd="usb_sync_wait",
  },
 },
 [2]={
  failed=false,
  done=true,
  status={
   status=true,
   cmd="usb_sync_wait",
  },
 },
 [3]={
  failed=false,
  done=true,
  status={
   status=true,
   cmd="usb_sync_wait",
  },
 },
 [4]={
  failed=false,
  done=true,
  status={
   status=true,
   cmd="usb_sync_wait",
  },
 },
 [5]={
  failed=false,
  done=true,
  status={
   status=true,
   cmd="usb_sync_wait",
  },
 },
 [6]={
  failed=false,
  done=true,
  status={
   status=true,
   cmd="usb_sync_wait",
  },
 },
 [7]={
  failed=false,
  done=true,
  status={
   status=true,
   cmd="usb_sync_wait",
  },
 },
 [8]={
  failed=false,
  done=true,
  status={
   status=true,
   cmd="usb_sync_wait",
  },
 },
 [9]={
  failed=false,
  done=true,
  status={
   status=true,
   cmd="usb_sync_wait",
  },
 },
 [10]={
  failed=false,
  done=true,
  status={
   status=true,
   cmd="usb_sync_wait",
  },
 },
 [11]={
  failed=false,
  done=true,
  status={
   status=true,
   cmd="usb_sync_wait",
  },
 },
 [12]={
  failed=false,
  done=true,
  status={
   status=true,
   cmd="usb_sync_wait",
  },
 },
 [13]={
  failed=false,
  done=true,
  status={
   status=true,
   cmd="usb_sync_wait",
  },
 },
 [14]={
  failed=false,
  done=true,
  status={
   status=true,
   cmd="usb_sync_wait",
  },
 },
 [15]={
  failed=false,
  done=true,
  status={
   status=true,
   cmd="usb_sync_wait",
  },
 },
 [16]={
  failed=false,
  done=true,
  status={
   status=true,
   cmd="usb_sync_wait",
  },
 },
}
___> !mc:download_images({lastimg=1,fmatch='JPG$'})
ERROR: call failed:I/O error

___> !mc:camstatus()
#1 connected
#2 NOT connected
#3 connected
#4 connected
#5 connected
#6 connected
#7 connected
#8 connected
#9 connected
#10 connected
#11 connected
#12 connected
#13 connected
#14 connected
#15 connected
#16 connected

Summary: 16 cameras (15 connected, 1 disconnected)
___>
« Last Edit: 05 / October / 2017, 14:21:28 by andrew.stephens.754365 »

*

Offline philmoz

  • *****
  • 3450
    • Photos
Re: suba threading bug (was Re: 3D scanner with multiple IXUS160 cameras)
« Reply #33 on: 05 / October / 2017, 16:58:02 »
With Phil's latest build (thankfully uploaded to all cameras using existing chdkptp):

Test was:

lock_ptp_comms
switch to record

repeat x 8

preshoot->usb_sync_shoot->open 5V switch->download to PC->delete camera image

was successful.

On the 9th cycle, at download an I/O error occurred and cam2 made the usb disconnect sound.

romlog attached (date is as per camera).


The ROMLOG error is from the free list check I added to the 'suba' code.
It indicates that the memory allocator free list has been corrupted somehow.


This could be a buffer overrun, or threading synchronisation issue with the 'suba' code.



Debugging this type of error is going to be hard unless we can find a way to reproduce it more easily than building a multi-cam rig.


I haven't read the entire thread in detail - is there a script (or set of steps) that I could run (on a single camera) to try and replicate what you are doing?


Did you notice any errors from the EXMEM_TESTING? This would be displayed at the bottom of the LCD in each camera as two rows of hex numbers. If there are no errors it displays 'OK: xxxxxxxx' where xxxxxxxx is the EXMEM start address.


Phil.
CHDK ports:
  sx30is (1.00c, 1.00h, 1.00l, 1.00n & 1.00p)
  g12 (1.00c, 1.00e, 1.00f & 1.00g)
  sx130is (1.01d & 1.01f)
  ixus310hs (1.00a & 1.01a)
  sx40hs (1.00d, 1.00g & 1.00i)
  g1x (1.00e, 1.00f & 1.00g)
  g5x (1.00c, 1.01a, 1.01b)
  g7x2 (1.01a, 1.01b, 1.10b)


*

Offline reyalp

  • ******
  • 14080
Re: suba threading bug (was Re: 3D scanner with multiple IXUS160 cameras)
« Reply #34 on: 05 / October / 2017, 23:26:49 »
I haven't read the entire thread in detail - is there a script (or set of steps) that I could run (on a single camera) to try and replicate what you are doing?
AFAIK andrew.stephens.754365 has only reproduced it using a multicam rig, and even there it takes multiple attempts.

If it's generic threading issue, I'd expect hammering USB while Lua is busy doing should be able to trigger it pretty quickly.
Don't forget what the H stands for.

*

Offline reyalp

  • ******
  • 14080
Re: suba threading bug (was Re: 3D scanner with multiple IXUS160 cameras)
« Reply #35 on: 06 / October / 2017, 02:34:09 »
OK, I can reproduce it, and I'm pretty sure it's a threading issue.

Using msgtest.lua chdkptp r749 (https://app.assembla.com/spaces/chdkptp/subversion/source/HEAD/trunk/lua/extras/msgtest.lua should work with existing chdkptp executables)

!mt=require'extras/msgtest'
!mt.test{size=100,sizemax=100,count=1000,busy=true}

gives me an exception vextor 0x10 in PTPSessionTA0 within a few hundred iterations.

I'd guess a semaphore protecting suba would probably fix this.

edit:
Verified that it's in the same place in suba_getmeminfo
« Last Edit: 06 / October / 2017, 02:37:11 by reyalp »
Don't forget what the H stands for.

*

Offline philmoz

  • *****
  • 3450
    • Photos
Re: suba threading bug (was Re: 3D scanner with multiple IXUS160 cameras)
« Reply #36 on: 06 / October / 2017, 03:50:18 »
!mt=require'extras/msgtest'
!mt.test{size=100,sizemax=100,count=1000,busy=true}

gives me an exception vextor 0x10 in PTPSessionTA0 within a few hundred iterations.


Just tried this on the G12 - 10,000 iterations and no error  ???
Update: also tried on the IXUS 310, still unable to reproduce the error.

I wonder if it is dependant on amount of free memory - i.e. could be a memory leak. G12 has > 4MB free.


Phil.
« Last Edit: 06 / October / 2017, 05:43:42 by philmoz »
CHDK ports:
  sx30is (1.00c, 1.00h, 1.00l, 1.00n & 1.00p)
  g12 (1.00c, 1.00e, 1.00f & 1.00g)
  sx130is (1.01d & 1.01f)
  ixus310hs (1.00a & 1.01a)
  sx40hs (1.00d, 1.00g & 1.00i)
  g1x (1.00e, 1.00f & 1.00g)
  g5x (1.00c, 1.01a, 1.01b)
  g7x2 (1.01a, 1.01b, 1.10b)

Re: suba threading bug (was Re: 3D scanner with multiple IXUS160 cameras)
« Reply #37 on: 06 / October / 2017, 03:59:08 »
I had planned to load 1000 jpg's on a single camera and use multicam:

!mc:delete_images_list(mc:imglist(),{verbose=true})

in attempt to precipitate the crash.

In light of most recent comments i'll assume that is no longer useful.
 
« Last Edit: 06 / October / 2017, 04:00:40 by andrew.stephens.754365 »


*

Offline reyalp

  • ******
  • 14080
Re: suba threading bug (was Re: 3D scanner with multiple IXUS160 cameras)
« Reply #38 on: 06 / October / 2017, 12:13:00 »
Just tried this on the G12 - 10,000 iterations and no error  ???
Double check you are using the correct version of extras/msgtest.lua file? The same command I posted would run with previous versions, but only the version I checked in last night has the "busy" test that triggers the crash for me.

Quote
I wonder if it is dependant on amount of free memory - i.e. could be a memory leak. G12 has > 4MB free.
Maybe it happens when the EXMEM/ARAM pool runs out I guess? You could try setting smaller sizes. sx160 has ARAM enabled, CHDK in EXMEM with 500kb of EXMEM (similar to the sx150 andrew.stephens.754365 is using)

edit: I don't really think these cameras should be close to running out with that test though...

I guess CHDK in EXMEM could be a factor too (e.g. size calculation wrong when CHDK is in EXMEM, but OK when it's not)

It obviously wouldn't happen on cameras that don't have one of the suba pools configured.
« Last Edit: 06 / October / 2017, 12:14:43 by reyalp »
Don't forget what the H stands for.

*

Offline philmoz

  • *****
  • 3450
    • Photos
Re: suba threading bug (was Re: 3D scanner with multiple IXUS160 cameras)
« Reply #39 on: 06 / October / 2017, 17:48:52 »
Just tried this on the G12 - 10,000 iterations and no error  ???
Double check you are using the correct version of extras/msgtest.lua file? The same command I posted would run with previous versions, but only the version I checked in last night has the "busy" test that triggers the crash for me.


That was it - I can reproduce the crash now.


Phil.

CHDK ports:
  sx30is (1.00c, 1.00h, 1.00l, 1.00n & 1.00p)
  g12 (1.00c, 1.00e, 1.00f & 1.00g)
  sx130is (1.01d & 1.01f)
  ixus310hs (1.00a & 1.01a)
  sx40hs (1.00d, 1.00g & 1.00i)
  g1x (1.00e, 1.00f & 1.00g)
  g5x (1.00c, 1.01a, 1.01b)
  g7x2 (1.01a, 1.01b, 1.10b)

 

Related Topics