Apache Cordova
  1. Apache Cordova
  2. CB-1404

EXC_BAD_ACCESS when using XHR_WITH_PAYLOAD bridge mode

    Details

    • Type: Bug Bug
    • Status: Resolved
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: 2.1.0
    • Fix Version/s: 2.2.0
    • Component/s: iOS
    • Labels:
      None
    • Environment:

      iPad 2, iOS 5.1.1

      Description

      When calling a plugin the app crashes on WebThread with EXC_BAD_ACCESS in WebCore::DocumentThreadableLoader::cancel.

      This appears to be some sort of timing issue, as it does not happen on every call - I am seeing it in an autosave function which makes lots of calls to PGSQLitePlugin.

      The error did not appear before upgrading to 2.1, and setting the bridge mode to IFRAME_NAV restores the previous behaviour (no crashes, but odd scrolling functionality).

      Setting the bridge mode to XHR_NO_PAYLOAD also seems to fix it - not sure if removing the payload actually does anything different or just makes it fast enough that the timing condition does not come up in normal app usage.

        Activity

        Hide
        Andrew Grieve added a comment -

        Thanks for the report Tom. Indeed it is suspicious that XHR_NO_PAYLOAD works around it. Do you have the full stack trace available?

        Show
        Andrew Grieve added a comment - Thanks for the report Tom. Indeed it is suspicious that XHR_NO_PAYLOAD works around it. Do you have the full stack trace available?
        Hide
        Tom Clarkson added a comment -

        I wasn't able to get a useful stack trace - there are no callers on the crashed thread, and none of the other threads show any user code.

        There is a possibility that there is a safari bug involved - I found a reference to an issue with cancelling requests (http://stackoverflow.com/a/8326429/101970) that while not an exact match, would explain the issue going away with XHR_NO_PAYLOAD - an empty request is unlikely to need cancelling.

        WebCore`WebCore::DocumentThreadableLoader::cancel():
        0x337d8018: push

        {r4, r5, r7, lr}

        0x337d801a: add r7, sp, #8
        0x337d801c: ldr r1, r0, #12
        0x337d801e: cmp r1, #0
        0x337d8020: it eq
        0x337d8022: popeq

        {r4, r5, r7, pc}
        0x337d8024: mov r4, r0
        0x337d8026: mov r0, r1
        0x337d8028: bl #-1208228 ; 0x336b1088 WebCore::ResourceLoader::cancel()
        0x337d802c: movs r5, #0
        0x337d802e: ldr r0, r4, #12
        0x337d8030: str.w r5, r0, #564 << Thread 5 WebThread EXC_BAD_ACCESS (code=1, address 0x234)
        0x337d8034: ldr r1, r4, #12
        0x337d8036: str r5, r4, #12
        0x337d8038: cbz r1, 0x337d8058 ; WebCore::DocumentThreadableLoader::cancel() + 64
        0x337d803a: mov r0, r1
        0x337d803c: ldr r2, r0, #4!
        0x337d8040: cmp r2, #1
        0x337d8042: beq 0x337d804c ; WebCore::DocumentThreadableLoader::cancel() + 52
        0x337d8044: subs r0, r2, #1
        0x337d8046: str r0, r1, #4
        0x337d8048: str r5, r4, #16
        0x337d804a: pop {r4, r5, r7, pc}

        0x337d804c: cmp r0, #4
        0x337d804e: beq 0x337d8058 ; WebCore::DocumentThreadableLoader::cancel() + 64
        0x337d8050: ldr r1, r0, #-4!
        0x337d8054: ldr r1, r1, #4
        0x337d8056: blx r1
        0x337d8058: str r5, r4, #16
        0x337d805a: pop

        {r4, r5, r7, pc}
        Show
        Tom Clarkson added a comment - I wasn't able to get a useful stack trace - there are no callers on the crashed thread, and none of the other threads show any user code. There is a possibility that there is a safari bug involved - I found a reference to an issue with cancelling requests ( http://stackoverflow.com/a/8326429/101970 ) that while not an exact match, would explain the issue going away with XHR_NO_PAYLOAD - an empty request is unlikely to need cancelling. WebCore`WebCore::DocumentThreadableLoader::cancel(): 0x337d8018: push {r4, r5, r7, lr} 0x337d801a: add r7, sp, #8 0x337d801c: ldr r1, r0, #12 0x337d801e: cmp r1, #0 0x337d8020: it eq 0x337d8022: popeq {r4, r5, r7, pc} 0x337d8024: mov r4, r0 0x337d8026: mov r0, r1 0x337d8028: bl #-1208228 ; 0x336b1088 WebCore::ResourceLoader::cancel() 0x337d802c: movs r5, #0 0x337d802e: ldr r0, r4, #12 0x337d8030: str.w r5, r0, #564 << Thread 5 WebThread EXC_BAD_ACCESS (code=1, address 0x234) 0x337d8034: ldr r1, r4, #12 0x337d8036: str r5, r4, #12 0x337d8038: cbz r1, 0x337d8058 ; WebCore::DocumentThreadableLoader::cancel() + 64 0x337d803a: mov r0, r1 0x337d803c: ldr r2, r0, #4 ! 0x337d8040: cmp r2, #1 0x337d8042: beq 0x337d804c ; WebCore::DocumentThreadableLoader::cancel() + 52 0x337d8044: subs r0, r2, #1 0x337d8046: str r0, r1, #4 0x337d8048: str r5, r4, #16 0x337d804a: pop {r4, r5, r7, pc} 0x337d804c: cmp r0, #4 0x337d804e: beq 0x337d8058 ; WebCore::DocumentThreadableLoader::cancel() + 64 0x337d8050: ldr r1, r0, #-4 ! 0x337d8054: ldr r1, r1, #4 0x337d8056: blx r1 0x337d8058: str r5, r4, #16 0x337d805a: pop {r4, r5, r7, pc}
        Hide
        Tom Clarkson added a comment -

        I have confirmed that the issue is not related to the plugin used - I added the below code to app startup calling the simplest plugin in the app.

        With XHR_WITH_PAYLOAD, it usually crashes with less than 100 calls, though it did get to over 2,000 a couple of times. In actual use with the sqlite plugin it was usually crashing in the first 20 calls, so the amount of work done in the plugin probably does have some effect.

        With XHR_NO_PAYLOAD, it is at 45,000 and still running.

        app.tryToCrash = function {

        console.log("reporting ready for file plugin");
        Cordova.exec(function(result) {
        console.log("plugin call "i" - "+result);
        window.setTimeout(function()

        {app.tryToCrash(i+1);}, 0);

        }, function(result) {
        console.log("plugin call "i" - "+result);
        window.setTimeout(function() {app.tryToCrash(i+1);}

        , 0);
        }, "FileStorePlugin", "reportReadyToOpenFiles", []);

        }

        • (void)reportReadyToOpenFiles:(NSMutableArray*)arguments withDict:(NSMutableDictionary*)options
          {

        NSString *callback = [arguments objectAtIndex:0];

        self.readyToOpenFiles = YES;

        CDVPluginResult* result = [CDVPluginResult resultWithStatus:CDVCommandStatus_OK messageAsString: @"ready"];

        [self writeJavascript:[result toSuccessCallbackString:callback]];

        if (self.queuedUrl != nil)

        { [self handleOpenUrlInternal:self.queuedUrl]; self.queuedUrl = nil; }

        }

        Show
        Tom Clarkson added a comment - I have confirmed that the issue is not related to the plugin used - I added the below code to app startup calling the simplest plugin in the app. With XHR_WITH_PAYLOAD, it usually crashes with less than 100 calls, though it did get to over 2,000 a couple of times. In actual use with the sqlite plugin it was usually crashing in the first 20 calls, so the amount of work done in the plugin probably does have some effect. With XHR_NO_PAYLOAD, it is at 45,000 and still running. app.tryToCrash = function { console.log("reporting ready for file plugin"); Cordova.exec(function(result) { console.log("plugin call " i " - "+result); window.setTimeout(function() {app.tryToCrash(i+1);}, 0); }, function(result) { console.log("plugin call " i " - "+result); window.setTimeout(function() {app.tryToCrash(i+1);} , 0); }, "FileStorePlugin", "reportReadyToOpenFiles", []); } (void)reportReadyToOpenFiles:(NSMutableArray*)arguments withDict:(NSMutableDictionary*)options { NSString *callback = [arguments objectAtIndex:0] ; self.readyToOpenFiles = YES; CDVPluginResult* result = [CDVPluginResult resultWithStatus:CDVCommandStatus_OK messageAsString: @"ready"] ; [self writeJavascript: [result toSuccessCallbackString:callback] ]; if (self.queuedUrl != nil) { [self handleOpenUrlInternal:self.queuedUrl]; self.queuedUrl = nil; } }
        Hide
        Andrew Grieve added a comment -

        Just tried for a while to repro this using the exec() benchmark in the mobile-spec tests. No success.

        Tom - did this happen for you in debug more or just release mode? when the device was attached to Xcode?

        Is the handleOpenUrlInternal:self part in your example relevant?

        For now - I think I'll just change the default mode to XHR_NO_PAYLOAD, but I'd like to keep looking at this and figure out what's going on. The payload is passed via a header of the XHR, and the XHR is never aborted, so it's weird that it works without a payload. Perhaps we could use query params instead, or just lower the threshold of how much data to send. I need to be able to repro it first though .

        I'm running 5.0.1 on my iPad 2, so I'll update to 5.1.1 and see if it makes a difference.

        Show
        Andrew Grieve added a comment - Just tried for a while to repro this using the exec() benchmark in the mobile-spec tests. No success. Tom - did this happen for you in debug more or just release mode? when the device was attached to Xcode? Is the handleOpenUrlInternal:self part in your example relevant? For now - I think I'll just change the default mode to XHR_NO_PAYLOAD, but I'd like to keep looking at this and figure out what's going on. The payload is passed via a header of the XHR, and the XHR is never aborted, so it's weird that it works without a payload. Perhaps we could use query params instead, or just lower the threshold of how much data to send. I need to be able to repro it first though . I'm running 5.0.1 on my iPad 2, so I'll update to 5.1.1 and see if it makes a difference.
        Show
        Andrew Grieve added a comment - Changed to XHR_NO_PAYLOAD. https://git-wip-us.apache.org/repos/asf?p=incubator-cordova-js.git;a=commit;h=650e5414e77ed77095fdf6ab2acac480d8489f74
        Hide
        Andrew Grieve added a comment -

        Going to re-open and set for 2.2.0 since I still want to figure out what's going on so we can re-enable payload bundling.

        Show
        Andrew Grieve added a comment - Going to re-open and set for 2.2.0 since I still want to figure out what's going on so we can re-enable payload bundling.
        Hide
        Tom Clarkson added a comment -

        So far I have only seen the crash while debugging - so potentially only seen by developers, but still a bit of a concern when we don't have an explanation.

        The queuedUrl code in that plugin is simply a one time handling of files opened before the app is ready - it won't run any more than the null check after the first call. In any case, I commented out everything except the three lines needed for the callback, and still got the error.

        I have taken the reproduction a couple of steps further. I created a new project and added the tryToCrash script to app.onDeviceReady. No error. I then replaced the www folder from my app project with the one from the new project. Also no error.

        The error only seems to come up when the more complex app is loaded. I removed most of the plugin calls from app startup (switching the sql plugin calls to web sql and removing the more complex custom plugin calls entirely) but still got the error. The app isn't doing anything other than calling the test plugin at the time it crashes - the only difference I can think of is that there is more stuff in memory than with a new template app.

        I also left the XHR_NO_PAYLOAD version of the app running overnight. I wasn't able to see how many calls it got to, but this morning the app was still running and xcode had become unresponsive with the size of the log.

        Show
        Tom Clarkson added a comment - So far I have only seen the crash while debugging - so potentially only seen by developers, but still a bit of a concern when we don't have an explanation. The queuedUrl code in that plugin is simply a one time handling of files opened before the app is ready - it won't run any more than the null check after the first call. In any case, I commented out everything except the three lines needed for the callback, and still got the error. I have taken the reproduction a couple of steps further. I created a new project and added the tryToCrash script to app.onDeviceReady. No error. I then replaced the www folder from my app project with the one from the new project. Also no error. The error only seems to come up when the more complex app is loaded. I removed most of the plugin calls from app startup (switching the sql plugin calls to web sql and removing the more complex custom plugin calls entirely) but still got the error. The app isn't doing anything other than calling the test plugin at the time it crashes - the only difference I can think of is that there is more stuff in memory than with a new template app. I also left the XHR_NO_PAYLOAD version of the app running overnight. I wasn't able to see how many calls it got to, but this morning the app was still running and xcode had become unresponsive with the size of the log.
        Hide
        Andrew Grieve added a comment -

        Thanks Tom, that's very useful info! Would you be able to attach a zip of your project that can repro the error? Or send it to me directly if you want to keep it out of the public eye? If not, that's fine too and I'll try testing this out in a more involved app. It does sounds like it might be memory related. Possibly XHR_WITH_PAYLOAD is leaking in some way.

        Show
        Andrew Grieve added a comment - Thanks Tom, that's very useful info! Would you be able to attach a zip of your project that can repro the error? Or send it to me directly if you want to keep it out of the public eye? If not, that's fine too and I'll try testing this out in a more involved app. It does sounds like it might be memory related. Possibly XHR_WITH_PAYLOAD is leaking in some way.
        Hide
        Tom Clarkson added a comment -

        Easiest is probably if I give you access to the github repo (https://github.com/tqc/ConceptualCSS/tree/crash) - what is your username?

        The www folder is generated with jekyll and included in .gitignore - let me know if you would prefer me to check in the generated files.

        Show
        Tom Clarkson added a comment - Easiest is probably if I give you access to the github repo ( https://github.com/tqc/ConceptualCSS/tree/crash ) - what is your username? The www folder is generated with jekyll and included in .gitignore - let me know if you would prefer me to check in the generated files.
        Hide
        Andrew Grieve added a comment -

        Okay, finally getting back to looking at this. Was able to update my iPad 2 to 5.1.1, so good to go on that front.

        My github id is agrieve.

        Show
        Andrew Grieve added a comment - Okay, finally getting back to looking at this. Was able to update my iPad 2 to 5.1.1, so good to go on that front. My github id is agrieve.
        Hide
        Tom Clarkson added a comment -

        You should have access to that code now if you still need to reproduce it, but I think I have tracked down the actual cause now.

        The key difference between XHR_WITH_PAYLOAD and XHR_NO_PAYLOAD is the use of commandQueueFlushing - it prevents a new request from being sent until it is unset as the final step of the previous request. Without that check, there is nothing to stop the second plugin call from running before execXhr is ready for reuse.

        A small change to exec fixes the issue:

        // execXhr = execXhr || new XMLHttpRequest();
        if (!execXhr || execXhr.readyState != 4) execXhr = new XMLHttpRequest();

        If the previous request has not finished, a new request is created so that the previous request can finish rather than being cancelled at a point which triggers a system bug.

        Show
        Tom Clarkson added a comment - You should have access to that code now if you still need to reproduce it, but I think I have tracked down the actual cause now. The key difference between XHR_WITH_PAYLOAD and XHR_NO_PAYLOAD is the use of commandQueueFlushing - it prevents a new request from being sent until it is unset as the final step of the previous request. Without that check, there is nothing to stop the second plugin call from running before execXhr is ready for reuse. A small change to exec fixes the issue: // execXhr = execXhr || new XMLHttpRequest(); if (!execXhr || execXhr.readyState != 4) execXhr = new XMLHttpRequest(); If the previous request has not finished, a new request is created so that the previous request can finish rather than being cancelled at a point which triggers a system bug.
        Hide
        Andrew Grieve added a comment -

        Tom, I like your reasoning. I didn't bother with trying your test case, but instead applied your patch:

        https://git-wip-us.apache.org/repos/asf?p=incubator-cordova-js.git;a=commit;h=533c707ee48f1191fde2d92376b1a5cc45e4a72a

        I've also changed the default bridge mode back to XHR_OPTIONAL_PAYLOAD.

        We can re-open if the crash shows up again.

        Show
        Andrew Grieve added a comment - Tom, I like your reasoning. I didn't bother with trying your test case, but instead applied your patch: https://git-wip-us.apache.org/repos/asf?p=incubator-cordova-js.git;a=commit;h=533c707ee48f1191fde2d92376b1a5cc45e4a72a I've also changed the default bridge mode back to XHR_OPTIONAL_PAYLOAD. We can re-open if the crash shows up again.
        Hide
        Shazron Abdullah added a comment -
        Show
        Shazron Abdullah added a comment - Possible issue according to this GG post: https://groups.google.com/d/topic/phonegap/TEJHy1942t8/discussion
        Hide
        john hight added a comment -

        As Shazron has suggested I pop in here, and that's my GG post above, I'll fill in some details here.

        With 2.2.0, on the IOS simulator, when recording two simultaneous audio files, stopRecord just "crashes" (quietly rails to return). The audio buffer recording does indeed stop, as I do get the usual log messages, but stopRecord does not return:

        --------
        2012-11-10 12:02:27.262 Test[15518:c07] Stopped recording audio sample '/Users/john/Library/Application Support/iPhone Simulator/6.0/Applications/6F937803-2C02-4FBC-8773-D9FD4BCB9568/tmp/audio0.wav'

        2012-11-10 12:02:27.264 Test[15518:c07] Finished recording audio sample '/Users/john/Library/Application Support/iPhone Simulator/6.0/Applications/6F937803-2C02-4FBC-8773-D9FD4BCB9568/tmp/audio0.wav'
        ---------

        I suspect some sort of race condition since the problem does not occur when I'm stepping through the source with the Safari debugger. Here's the (I believe) relevant piece of code:

        // Re-using the XHR improves exec() performance by about 10%.
        // It is possible for a native stringByEvaluatingJavascriptFromString call
        // to cause us to reach this point when a request is already in progress,
        // so we check the readyState to guard agains re-using an inprogress XHR.
        // Refer to CB-1404.
        if (execXhr && execXhr.readyState != 4)

        { execXhr = null; }

        execXhr = execXhr || new XMLHttpRequest();

        Stepping into the stopRecord call with thr debugger, the "if expression" at line 1017 evaluates to False, and subsequently, we reuse the execXhr (we don't make a new one), the constructor is not called, and stopRecord returns as it should. Without the debugger, just the simulator, the "if expression" evaluates True, execXhr is set null, and we next attempt to create a new execXhr, and the code silently fails within the call to the constructor.

        Perhaps there is still some issue with regard to CB-1404?

        Show
        john hight added a comment - As Shazron has suggested I pop in here, and that's my GG post above, I'll fill in some details here. With 2.2.0, on the IOS simulator, when recording two simultaneous audio files, stopRecord just "crashes" (quietly rails to return). The audio buffer recording does indeed stop, as I do get the usual log messages, but stopRecord does not return: -------- 2012-11-10 12:02:27.262 Test [15518:c07] Stopped recording audio sample '/Users/john/Library/Application Support/iPhone Simulator/6.0/Applications/6F937803-2C02-4FBC-8773-D9FD4BCB9568/tmp/audio0.wav' 2012-11-10 12:02:27.264 Test [15518:c07] Finished recording audio sample '/Users/john/Library/Application Support/iPhone Simulator/6.0/Applications/6F937803-2C02-4FBC-8773-D9FD4BCB9568/tmp/audio0.wav' --------- I suspect some sort of race condition since the problem does not occur when I'm stepping through the source with the Safari debugger. Here's the (I believe) relevant piece of code: // Re-using the XHR improves exec() performance by about 10%. // It is possible for a native stringByEvaluatingJavascriptFromString call // to cause us to reach this point when a request is already in progress, // so we check the readyState to guard agains re-using an inprogress XHR. // Refer to CB-1404 . if (execXhr && execXhr.readyState != 4) { execXhr = null; } execXhr = execXhr || new XMLHttpRequest(); Stepping into the stopRecord call with thr debugger, the "if expression" at line 1017 evaluates to False, and subsequently, we reuse the execXhr (we don't make a new one), the constructor is not called, and stopRecord returns as it should. Without the debugger, just the simulator, the "if expression" evaluates True, execXhr is set null, and we next attempt to create a new execXhr, and the code silently fails within the call to the constructor. Perhaps there is still some issue with regard to CB-1404 ?
        Hide
        Andrew Grieve added a comment -

        Hmm, yeah, not sure what's going on. If it's reproducible, might be worth putting a try/catch in there to see if a JS exception is happening.

        Of note:
        -XHR_WITH_PAYLOAD is not used in 2.2 by default. It's always NO_PAYLOAD.
        -This CL makes it even less likely to attempt an XHR when there is already one in progress: https://git-wip-us.apache.org/repos/asf?p=incubator-cordova-js.git;a=blobdiff;f=lib/ios/exec.js;h=7ce52d94da0e834104e0ee5cc1ceb70e8cbe8104;hp=c6b8edd7f9518c0a1ca726db2216f64a45a0e0a7;hb=86411246aba4292734b9bb46dc9128e28391e424;hpb=c3517e7703ab9a1335db8a3d0974b045ae3107e5

        Show
        Andrew Grieve added a comment - Hmm, yeah, not sure what's going on. If it's reproducible, might be worth putting a try/catch in there to see if a JS exception is happening. Of note: -XHR_WITH_PAYLOAD is not used in 2.2 by default. It's always NO_PAYLOAD. -This CL makes it even less likely to attempt an XHR when there is already one in progress: https://git-wip-us.apache.org/repos/asf?p=incubator-cordova-js.git;a=blobdiff;f=lib/ios/exec.js;h=7ce52d94da0e834104e0ee5cc1ceb70e8cbe8104;hp=c6b8edd7f9518c0a1ca726db2216f64a45a0e0a7;hb=86411246aba4292734b9bb46dc9128e28391e424;hpb=c3517e7703ab9a1335db8a3d0974b045ae3107e5
        Hide
        Andrew Grieve added a comment -

        John, would you be willing to upload a zip of your multi-recording test app to this bug? Reproducing the bug is step #1.

        Show
        Andrew Grieve added a comment - John, would you be willing to upload a zip of your multi-recording test app to this bug? Reproducing the bug is step #1.
        Hide
        john hight added a comment -

        I'd be glad to ... except that due to some "un-thriftiness" on my part,
        I've got a lot of images ballooning the size up to about 64MB. I'll see if
        I can get the size ratcheted down. Unless, of course, you're ok with
        getting it off of github:
        https://github.com/johnhight/AudioRecall.git(I'll have it public for a
        bit)

        Show
        john hight added a comment - I'd be glad to ... except that due to some "un-thriftiness" on my part, I've got a lot of images ballooning the size up to about 64MB. I'll see if I can get the size ratcheted down. Unless, of course, you're ok with getting it off of github: https://github.com/johnhight/AudioRecall.git(I'll have it public for a bit)
        Hide
        john hight added a comment -

        Oops, nevermind, I'm a newbie to JIRA, didn't know I could attach-upload a
        file on the site. I'll upload.

        Show
        john hight added a comment - Oops, nevermind, I'm a newbie to JIRA, didn't know I could attach-upload a file on the site. I'll upload.
        Hide
        john hight added a comment -

        Too large to upload as well, it will be on github til I figure out how to make it smaller.

        Show
        john hight added a comment - Too large to upload as well, it will be on github til I figure out how to make it smaller.
        Hide
        Andrew Grieve added a comment -

        Great, I've cloned it and will have a look at it tomorrow.

        Show
        Andrew Grieve added a comment - Great, I've cloned it and will have a look at it tomorrow.
        Hide
        Andrew Grieve added a comment -

        Running it in the simulator, I click "Listen" and then "Sleep". Upon hitting "Sleep", I get 2 alerts, the second one being "Returned from stopRecord". Is this not what you're seeing?

        If a JS function seems to not return, it's almost certainly due to a JS exception being thrown. Adding a try/catch around it and logging the exception would help track it down.

        Show
        Andrew Grieve added a comment - Running it in the simulator, I click "Listen" and then "Sleep". Upon hitting "Sleep", I get 2 alerts, the second one being "Returned from stopRecord". Is this not what you're seeing? If a JS function seems to not return, it's almost certainly due to a JS exception being thrown. Adding a try/catch around it and logging the exception would help track it down.
        Hide
        john hight added a comment -

        I've tried putting a try/catch around the call to stopRecord, and it
        doesn't hit. I've also tried putting a try/catch around a few spots in
        iOSexec, and they don't either .... ALTHOUGH ... at one point I thought I
        saw a "DOM exception", perhaps '11', appear as a value in the Safari
        debugger as a property ("status" perhaps) of some variable in the sidebar.
        Couldn't reproduce that behavior though, and it may have been something
        that popped by putting one-too-many try/catch's or console.logs in iOSexec.

        The secret to reproducing the error is to:

        • click on Listen
        • wait for a little more than 10 seconds and then click on Capture.
          only have 10 seconds does the 2nd (of two) buffer/files start getting
          recorded. You will see log messages for the 2nd buffer, buffer1,
          like "*012-11-15
          09:55:46.257 AudioRecall[28435:c07] [LOG] buffer1 listening .... 1.007 sec,
        • ", when the 2nd buffer starts being recorded

        If it still hits the alert "Returned from stopRecord" then we've failed in
        getting you to reproduce the problem. If however, you do not get that
        specific alert, and instead get a different one, like "buffer1 while listen
        and default...." then you've reproduced the problem.

        Show
        john hight added a comment - I've tried putting a try/catch around the call to stopRecord, and it doesn't hit. I've also tried putting a try/catch around a few spots in iOSexec, and they don't either .... ALTHOUGH ... at one point I thought I saw a "DOM exception", perhaps '11', appear as a value in the Safari debugger as a property ("status" perhaps) of some variable in the sidebar. Couldn't reproduce that behavior though, and it may have been something that popped by putting one-too-many try/catch's or console.logs in iOSexec. The secret to reproducing the error is to: click on Listen wait for a little more than 10 seconds and then click on Capture. only have 10 seconds does the 2nd (of two) buffer/files start getting recorded. You will see log messages for the 2nd buffer, buffer1, like "*012-11-15 09:55:46.257 AudioRecall [28435:c07] [LOG] buffer1 listening .... 1.007 sec, ", when the 2nd buffer starts being recorded If it still hits the alert "Returned from stopRecord" then we've failed in getting you to reproduce the problem. If however, you do not get that specific alert, and instead get a different one, like "buffer1 while listen and default...." then you've reproduced the problem.
        Hide
        Andrew Grieve added a comment -

        Okay, I tried it again on the iOS 6 simulator. Wait for 10 seconds watching the logs, at 10 seconds a bunch more spew out. I then click Capture.

        I see a "buffer1 while listen and default..." alert, and once I dismiss it, I see the returned from stopRecord alert.

        Show
        Andrew Grieve added a comment - Okay, I tried it again on the iOS 6 simulator. Wait for 10 seconds watching the logs, at 10 seconds a bunch more spew out. I then click Capture. I see a "buffer1 while listen and default..." alert, and once I dismiss it, I see the returned from stopRecord alert.
        Hide
        john hight added a comment -

        I believe you've replicated the bug since the first alert you get is not
        the stopRecord alert. The stopRecord alert you subsequently see is
        "probably" the return from the second of two stopRecords that get issued
        (one for each file), but it could be misleading to even guess at that since
        anything after the first "problem" (the last of stopRecord alert first)
        could be hard to predict.

        Show
        john hight added a comment - I believe you've replicated the bug since the first alert you get is not the stopRecord alert. The stopRecord alert you subsequently see is "probably" the return from the second of two stopRecords that get issued (one for each file), but it could be misleading to even guess at that since anything after the first "problem" (the last of stopRecord alert first) could be hard to predict.
        Hide
        Andrew Grieve added a comment -

        I added some logging to the exec bridge to try and figure out what's going on. The app is a bit hard for me to follow what's going on, and I'm having a hard time figuring out if it's a cordova problem, or just a problem with your app.

        Here are the logs with all bridge calls logged:

        2012-11-15 18:48:58.830 AudioRecall[33258:c07] Multi-tasking -> Device: YES, App: YES
        2012-11-15 18:48:59.075 AudioRecall[33258:c07] [LOG] exec() NetworkStatus.getConnectionInfo ID=NetworkStatus727560950 args=[]
        2012-11-15 18:48:59.076 AudioRecall[33258:c07] [LOG] exec() Device.getDeviceInfo ID=Device727560951 args=[]
        2012-11-15 18:48:59.078 AudioRecall[33258:c07] [LOG] exec() CALLBACK: id=NetworkStatus727560950 status=1 args=["wifi"]
        2012-11-15 18:48:59.078 AudioRecall[33258:c07] [LOG] exec() CALLBACK: id=Device727560951 status=1 args=[

        {"name":"iPhone Simulator","uuid":"73B3D5D9-74A2-46D5-A1A4-01EFB5241C7F","platform":"iPhone Simulator","version":"6.0","cordova":"2.2.0"}

        ]
        2012-11-15 18:48:59.083 AudioRecall[33258:c07] [LOG] deviceready######################################################################
        2012-11-15 18:48:59.083 AudioRecall[33258:c07] [LOG] exec() File.requestFileSystem ID=File727560952 args=[0,0]
        2012-11-15 18:48:59.085 AudioRecall[33258:c07] [LOG] exec() CALLBACK: id=File727560952 status=1 args=[{"name":"temporary","root":{"name":"tmp","isFile":false,"isDirectory":true,"fullPath":"/Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/tmp"}}]
        2012-11-15 18:48:59.086 AudioRecall[33258:c07] [LOG] exec() File.readEntries ID=File727560953 args=["/Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/tmp"]
        2012-11-15 18:48:59.087 AudioRecall[33258:c07] [LOG] exec() CALLBACK: id=File727560953 status=1 args=[[

        {"name":"audio0.wav","isFile":true,"isDirectory":false,"fullPath":"/Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/tmp/audio0.wav"}

        ,

        {"name":"audio1.wav","isFile":true,"isDirectory":false,"fullPath":"/Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/tmp/audio1.wav"}

        ]]
        2012-11-15 18:48:59.088 AudioRecall[33258:c07] [LOG] exec() File.getFile ID=File727560954 args=["/Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/tmp","audio0.wav",{}]
        2012-11-15 18:48:59.089 AudioRecall[33258:c07] [LOG] exec() File.getFile ID=File727560955 args=["/Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/tmp","audio1.wav",{}]
        2012-11-15 18:48:59.089 AudioRecall[33258:c07] [LOG] exec() CALLBACK: id=File727560954 status=1 args=[

        {"name":"audio0.wav","isFile":true,"isDirectory":false,"fullPath":"/Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/tmp/audio0.wav"}

        ]
        2012-11-15 18:48:59.090 AudioRecall[33258:c07] [LOG] exec() CALLBACK: id=File727560955 status=1 args=[

        {"name":"audio1.wav","isFile":true,"isDirectory":false,"fullPath":"/Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/tmp/audio1.wav"}

        ]
        2012-11-15 18:48:59.091 AudioRecall[33258:c07] [LOG] exec() File.requestFileSystem ID=File727560956 args=[1,0]
        2012-11-15 18:48:59.093 AudioRecall[33258:c07] [LOG] exec() CALLBACK: id=File727560956 status=1 args=[{"name":"persistent","root":{"name":"Documents","isFile":false,"isDirectory":true,"fullPath":"/Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/Documents"}}]
        2012-11-15 18:48:59.093 AudioRecall[33258:c07] [LOG] exec() File.getDirectory ID=File727560957 args=["/Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/Documents","SAVED",

        {"create":false}

        ]
        2012-11-15 18:48:59.094 AudioRecall[33258:c07] [LOG] exec() CALLBACK: id=File727560957 status=1 args=[

        {"name":"SAVED","isFile":false,"isDirectory":true,"fullPath":"/Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/Documents/SAVED"}

        ]
        2012-11-15 18:48:59.096 AudioRecall[33258:c07] [LOG] changing mode from UNDEFINED to SLEEP
        2012-11-15 18:49:00.996 AudioRecall[33258:c07] [LOG] changing mode from SLEEP to LISTEN
        2012-11-15 18:49:00.996 AudioRecall[33258:c07] [LOG] buffer0, was UNUSED, will mark STARTED
        2012-11-15 18:49:00.998 AudioRecall[33258:c07] [LOG] buffer0 changing from UNUSED to STARTED, reason='sLOB'
        2012-11-15 18:49:00.999 AudioRecall[33258:c07] [LOG] making media for /Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/tmp/audio0.wav
        2012-11-15 18:49:01.000 AudioRecall[33258:c07] [LOG] exec() Media.create ID=Media727560958 args=["59c1457c-f79c-d719-9e1a-304e1218beda","/Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/tmp/audio0.wav"]
        2012-11-15 18:49:01.002 AudioRecall[33258:c07] Will attempt to use file resource '/Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/tmp/audio0.wav'
        2012-11-15 18:49:01.002 AudioRecall[33258:c07] [LOG] exec() CALLBACK: id=Media727560958 status=1 args=["OK"]
        2012-11-15 18:49:01.003 AudioRecall[33258:c07] [LOG] exec() Media.startRecordingAudio ID=Media727560959 args=["59c1457c-f79c-d719-9e1a-304e1218beda","/Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/tmp/audio0.wav"]
        2012-11-15 18:49:01.055 AudioRecall[33258:c07] Started recording audio sample '/Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/tmp/audio0.wav'
        2012-11-15 18:49:02.060 AudioRecall[33258:c07] [LOG] buffer0 listening .... 1.065 sec
        2012-11-15 18:49:03.061 AudioRecall[33258:c07] [LOG] buffer0 listening .... 2.065 sec
        2012-11-15 18:49:04.061 AudioRecall[33258:c07] [LOG] buffer0 listening .... 3.065 sec
        2012-11-15 18:49:05.061 AudioRecall[33258:c07] [LOG] buffer0 listening .... 4.065 sec
        2012-11-15 18:49:06.062 AudioRecall[33258:c07] [LOG] buffer0 listening .... 5.066 sec
        2012-11-15 18:49:07.062 AudioRecall[33258:c07] [LOG] buffer0 listening .... 6.066 sec
        2012-11-15 18:49:08.063 AudioRecall[33258:c07] [LOG] buffer0 listening .... 7.066 sec
        2012-11-15 18:49:09.063 AudioRecall[33258:c07] [LOG] buffer0 listening .... 8.066 sec
        2012-11-15 18:49:10.063 AudioRecall[33258:c07] [LOG] buffer0 listening .... 9.067 sec
        2012-11-15 18:49:11.061 AudioRecall[33258:c07] [LOG] buffer1, was UNUSED, will mark STARTED
        2012-11-15 18:49:11.062 AudioRecall[33258:c07] [LOG] buffer1 changing from UNUSED to STARTED, reason='sLOB'
        2012-11-15 18:49:11.063 AudioRecall[33258:c07] [LOG] making media for /Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/tmp/audio1.wav
        2012-11-15 18:49:11.064 AudioRecall[33258:c07] [LOG] exec() Media.create ID=Media727560960 args=["0f4a04ef-2a1d-1cb3-6662-0cf1448776ae","/Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/tmp/audio1.wav"]
        2012-11-15 18:49:11.065 AudioRecall[33258:c07] Will attempt to use file resource '/Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/tmp/audio1.wav'
        2012-11-15 18:49:11.066 AudioRecall[33258:c07] [LOG] exec() CALLBACK: id=Media727560960 status=1 args=["OK"]
        2012-11-15 18:49:11.067 AudioRecall[33258:c07] [LOG] exec() Media.startRecordingAudio ID=Media727560961 args=["0f4a04ef-2a1d-1cb3-6662-0cf1448776ae","/Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/tmp/audio1.wav"]
        2012-11-15 18:49:11.075 AudioRecall[33258:c07] Started recording audio sample '/Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/tmp/audio1.wav'
        2012-11-15 18:49:11.077 AudioRecall[33258:c07] [LOG] buffer0 listening .... 10.082 sec
        2012-11-15 18:49:12.078 AudioRecall[33258:c07] [LOG] buffer1 listening .... 1.017 sec
        2012-11-15 18:49:12.079 AudioRecall[33258:c07] [LOG] buffer0 listening .... 11.084 sec
        2012-11-15 18:49:12.720 AudioRecall[33258:c07] [LOG] buffer1 LISTENing STOP 1659
        2012-11-15 18:49:12.721 AudioRecall[33258:c07] [LOG] buffer1 has audioMedia that needs to be stopped
        2012-11-15 18:49:12.723 AudioRecall[33258:c07] [LOG] exec() Media.stopRecordingAudio ID=Media727560962 args=["0f4a04ef-2a1d-1cb3-6662-0cf1448776ae"]
        2012-11-15 18:49:12.724 AudioRecall[33258:c07] Stopped recording audio sample '/Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/tmp/audio1.wav'
        2012-11-15 18:49:12.736 AudioRecall[33258:c07] Finished recording audio sample '/Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/tmp/audio1.wav'
        2012-11-15 18:49:15.805 AudioRecall[33258:c07] [LOG] buffer1 changing from STARTED to PENDING_COMPLETE_NO_RESTART, reason='function stopBuffer'
        2012-11-15 18:49:15.806 AudioRecall[33258:c07] [LOG] changing mode from LISTEN to CAPTURE
        2012-11-15 18:49:16.145 AudioRecall[33258:c07] [LOG] buffer0 capturing .... 15.149 sec
        2012-11-15 18:49:17.145 AudioRecall[33258:c07] [LOG] buffer0 capturing .... 16.149 sec
        2012-11-15 18:49:18.145 AudioRecall[33258:c07] [LOG] buffer0 capturing .... 17.149 sec

        Show
        Andrew Grieve added a comment - I added some logging to the exec bridge to try and figure out what's going on. The app is a bit hard for me to follow what's going on, and I'm having a hard time figuring out if it's a cordova problem, or just a problem with your app. Here are the logs with all bridge calls logged: 2012-11-15 18:48:58.830 AudioRecall [33258:c07] Multi-tasking -> Device: YES, App: YES 2012-11-15 18:48:59.075 AudioRecall [33258:c07] [LOG] exec() NetworkStatus.getConnectionInfo ID=NetworkStatus727560950 args=[] 2012-11-15 18:48:59.076 AudioRecall [33258:c07] [LOG] exec() Device.getDeviceInfo ID=Device727560951 args=[] 2012-11-15 18:48:59.078 AudioRecall [33258:c07] [LOG] exec() CALLBACK: id=NetworkStatus727560950 status=1 args= ["wifi"] 2012-11-15 18:48:59.078 AudioRecall [33258:c07] [LOG] exec() CALLBACK: id=Device727560951 status=1 args=[ {"name":"iPhone Simulator","uuid":"73B3D5D9-74A2-46D5-A1A4-01EFB5241C7F","platform":"iPhone Simulator","version":"6.0","cordova":"2.2.0"} ] 2012-11-15 18:48:59.083 AudioRecall [33258:c07] [LOG] deviceready###################################################################### 2012-11-15 18:48:59.083 AudioRecall [33258:c07] [LOG] exec() File.requestFileSystem ID=File727560952 args= [0,0] 2012-11-15 18:48:59.085 AudioRecall [33258:c07] [LOG] exec() CALLBACK: id=File727560952 status=1 args= [{"name":"temporary","root":{"name":"tmp","isFile":false,"isDirectory":true,"fullPath":"/Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/tmp"}}] 2012-11-15 18:48:59.086 AudioRecall [33258:c07] [LOG] exec() File.readEntries ID=File727560953 args= ["/Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/tmp"] 2012-11-15 18:48:59.087 AudioRecall [33258:c07] [LOG] exec() CALLBACK: id=File727560953 status=1 args=[[ {"name":"audio0.wav","isFile":true,"isDirectory":false,"fullPath":"/Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/tmp/audio0.wav"} , {"name":"audio1.wav","isFile":true,"isDirectory":false,"fullPath":"/Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/tmp/audio1.wav"} ]] 2012-11-15 18:48:59.088 AudioRecall [33258:c07] [LOG] exec() File.getFile ID=File727560954 args= ["/Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/tmp","audio0.wav",{}] 2012-11-15 18:48:59.089 AudioRecall [33258:c07] [LOG] exec() File.getFile ID=File727560955 args= ["/Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/tmp","audio1.wav",{}] 2012-11-15 18:48:59.089 AudioRecall [33258:c07] [LOG] exec() CALLBACK: id=File727560954 status=1 args=[ {"name":"audio0.wav","isFile":true,"isDirectory":false,"fullPath":"/Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/tmp/audio0.wav"} ] 2012-11-15 18:48:59.090 AudioRecall [33258:c07] [LOG] exec() CALLBACK: id=File727560955 status=1 args=[ {"name":"audio1.wav","isFile":true,"isDirectory":false,"fullPath":"/Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/tmp/audio1.wav"} ] 2012-11-15 18:48:59.091 AudioRecall [33258:c07] [LOG] exec() File.requestFileSystem ID=File727560956 args= [1,0] 2012-11-15 18:48:59.093 AudioRecall [33258:c07] [LOG] exec() CALLBACK: id=File727560956 status=1 args= [{"name":"persistent","root":{"name":"Documents","isFile":false,"isDirectory":true,"fullPath":"/Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/Documents"}}] 2012-11-15 18:48:59.093 AudioRecall [33258:c07] [LOG] exec() File.getDirectory ID=File727560957 args=["/Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/Documents","SAVED", {"create":false} ] 2012-11-15 18:48:59.094 AudioRecall [33258:c07] [LOG] exec() CALLBACK: id=File727560957 status=1 args=[ {"name":"SAVED","isFile":false,"isDirectory":true,"fullPath":"/Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/Documents/SAVED"} ] 2012-11-15 18:48:59.096 AudioRecall [33258:c07] [LOG] changing mode from UNDEFINED to SLEEP 2012-11-15 18:49:00.996 AudioRecall [33258:c07] [LOG] changing mode from SLEEP to LISTEN 2012-11-15 18:49:00.996 AudioRecall [33258:c07] [LOG] buffer0, was UNUSED, will mark STARTED 2012-11-15 18:49:00.998 AudioRecall [33258:c07] [LOG] buffer0 changing from UNUSED to STARTED, reason='sLOB' 2012-11-15 18:49:00.999 AudioRecall [33258:c07] [LOG] making media for /Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/tmp/audio0.wav 2012-11-15 18:49:01.000 AudioRecall [33258:c07] [LOG] exec() Media.create ID=Media727560958 args= ["59c1457c-f79c-d719-9e1a-304e1218beda","/Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/tmp/audio0.wav"] 2012-11-15 18:49:01.002 AudioRecall [33258:c07] Will attempt to use file resource '/Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/tmp/audio0.wav' 2012-11-15 18:49:01.002 AudioRecall [33258:c07] [LOG] exec() CALLBACK: id=Media727560958 status=1 args= ["OK"] 2012-11-15 18:49:01.003 AudioRecall [33258:c07] [LOG] exec() Media.startRecordingAudio ID=Media727560959 args= ["59c1457c-f79c-d719-9e1a-304e1218beda","/Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/tmp/audio0.wav"] 2012-11-15 18:49:01.055 AudioRecall [33258:c07] Started recording audio sample '/Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/tmp/audio0.wav' 2012-11-15 18:49:02.060 AudioRecall [33258:c07] [LOG] buffer0 listening .... 1.065 sec 2012-11-15 18:49:03.061 AudioRecall [33258:c07] [LOG] buffer0 listening .... 2.065 sec 2012-11-15 18:49:04.061 AudioRecall [33258:c07] [LOG] buffer0 listening .... 3.065 sec 2012-11-15 18:49:05.061 AudioRecall [33258:c07] [LOG] buffer0 listening .... 4.065 sec 2012-11-15 18:49:06.062 AudioRecall [33258:c07] [LOG] buffer0 listening .... 5.066 sec 2012-11-15 18:49:07.062 AudioRecall [33258:c07] [LOG] buffer0 listening .... 6.066 sec 2012-11-15 18:49:08.063 AudioRecall [33258:c07] [LOG] buffer0 listening .... 7.066 sec 2012-11-15 18:49:09.063 AudioRecall [33258:c07] [LOG] buffer0 listening .... 8.066 sec 2012-11-15 18:49:10.063 AudioRecall [33258:c07] [LOG] buffer0 listening .... 9.067 sec 2012-11-15 18:49:11.061 AudioRecall [33258:c07] [LOG] buffer1, was UNUSED, will mark STARTED 2012-11-15 18:49:11.062 AudioRecall [33258:c07] [LOG] buffer1 changing from UNUSED to STARTED, reason='sLOB' 2012-11-15 18:49:11.063 AudioRecall [33258:c07] [LOG] making media for /Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/tmp/audio1.wav 2012-11-15 18:49:11.064 AudioRecall [33258:c07] [LOG] exec() Media.create ID=Media727560960 args= ["0f4a04ef-2a1d-1cb3-6662-0cf1448776ae","/Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/tmp/audio1.wav"] 2012-11-15 18:49:11.065 AudioRecall [33258:c07] Will attempt to use file resource '/Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/tmp/audio1.wav' 2012-11-15 18:49:11.066 AudioRecall [33258:c07] [LOG] exec() CALLBACK: id=Media727560960 status=1 args= ["OK"] 2012-11-15 18:49:11.067 AudioRecall [33258:c07] [LOG] exec() Media.startRecordingAudio ID=Media727560961 args= ["0f4a04ef-2a1d-1cb3-6662-0cf1448776ae","/Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/tmp/audio1.wav"] 2012-11-15 18:49:11.075 AudioRecall [33258:c07] Started recording audio sample '/Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/tmp/audio1.wav' 2012-11-15 18:49:11.077 AudioRecall [33258:c07] [LOG] buffer0 listening .... 10.082 sec 2012-11-15 18:49:12.078 AudioRecall [33258:c07] [LOG] buffer1 listening .... 1.017 sec 2012-11-15 18:49:12.079 AudioRecall [33258:c07] [LOG] buffer0 listening .... 11.084 sec 2012-11-15 18:49:12.720 AudioRecall [33258:c07] [LOG] buffer1 LISTENing STOP 1659 2012-11-15 18:49:12.721 AudioRecall [33258:c07] [LOG] buffer1 has audioMedia that needs to be stopped 2012-11-15 18:49:12.723 AudioRecall [33258:c07] [LOG] exec() Media.stopRecordingAudio ID=Media727560962 args= ["0f4a04ef-2a1d-1cb3-6662-0cf1448776ae"] 2012-11-15 18:49:12.724 AudioRecall [33258:c07] Stopped recording audio sample '/Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/tmp/audio1.wav' 2012-11-15 18:49:12.736 AudioRecall [33258:c07] Finished recording audio sample '/Users/agrieve/Library/Application Support/iPhone Simulator/6.0/Applications/FF5092AB-FBFD-4B11-B50D-C5EFDC73185F/tmp/audio1.wav' 2012-11-15 18:49:15.805 AudioRecall [33258:c07] [LOG] buffer1 changing from STARTED to PENDING_COMPLETE_NO_RESTART, reason='function stopBuffer' 2012-11-15 18:49:15.806 AudioRecall [33258:c07] [LOG] changing mode from LISTEN to CAPTURE 2012-11-15 18:49:16.145 AudioRecall [33258:c07] [LOG] buffer0 capturing .... 15.149 sec 2012-11-15 18:49:17.145 AudioRecall [33258:c07] [LOG] buffer0 capturing .... 16.149 sec 2012-11-15 18:49:18.145 AudioRecall [33258:c07] [LOG] buffer0 capturing .... 17.149 sec
        Hide
        john hight added a comment -

        Some details to help understand what the app is doing:

        • When LISTENing, the app is recording two files. Each file records for
          20 seconds, stops (with stopRecord), and then starts recording again.
          Additionally, one of the two files (buffer1) does not start off its
          sequence until the 10 second mark. The app is meant to have each file stop
          and restart approximately halfway through the recording of the other buffer.
        • In the scenario for reproducing the bug, you start the listening
          sequence by clicking LISTEN. buffer0 starts recording, and 10 seconds
          later, buffer1 starts recording.
        • Clicking CAPTURE after the 10 second mark essentially stops the
          recording of buffer1 and continues to let buffer0 record (for a much longer
          period of time), and causes the LISTEN file/buffer cycling to stop.
        • It's this call to stopRecord for buffer1 after the 10 sec mark that
          reproduces the problem.
        • The alert() placed after the call to stopRecord is only there
          temporarily to help try and diagnose the problem If that alert is not the
          first alert hit after clicking CAPTURE after 10 seconds, then the bug has
          been reproduced (and forget about what any other alert may proclaim).

        John

        Show
        john hight added a comment - Some details to help understand what the app is doing: When LISTENing, the app is recording two files. Each file records for 20 seconds, stops (with stopRecord), and then starts recording again. Additionally, one of the two files (buffer1) does not start off its sequence until the 10 second mark. The app is meant to have each file stop and restart approximately halfway through the recording of the other buffer. In the scenario for reproducing the bug, you start the listening sequence by clicking LISTEN. buffer0 starts recording, and 10 seconds later, buffer1 starts recording. Clicking CAPTURE after the 10 second mark essentially stops the recording of buffer1 and continues to let buffer0 record (for a much longer period of time), and causes the LISTEN file/buffer cycling to stop. It's this call to stopRecord for buffer1 after the 10 sec mark that reproduces the problem. The alert() placed after the call to stopRecord is only there temporarily to help try and diagnose the problem If that alert is not the first alert hit after clicking CAPTURE after 10 seconds, then the bug has been reproduced (and forget about what any other alert may proclaim). John
        Hide
        Andrew Grieve added a comment -

        Why do you think it's not working if I'm seeing the alert? there is one call to stopRecord, and the alert after it does show. Why does the other alert showing first mean that something is wrong?

        Show
        Andrew Grieve added a comment - Why do you think it's not working if I'm seeing the alert? there is one call to stopRecord, and the alert after it does show. Why does the other alert showing first mean that something is wrong?
        Hide
        john hight added a comment -

        Problem solved. I had my blinders on regarding the order that callbacks
        come in sometimes.

        Thanks for setting my straight

        Show
        john hight added a comment - Problem solved. I had my blinders on regarding the order that callbacks come in sometimes. Thanks for setting my straight
        Hide
        Andrew Grieve added a comment -

        Glad to hear it! Thanks for following through on a bug report either way

        Show
        Andrew Grieve added a comment - Glad to hear it! Thanks for following through on a bug report either way

          People

          • Assignee:
            Andrew Grieve
            Reporter:
            Tom Clarkson
          • Votes:
            0 Vote for this issue
            Watchers:
            4 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development