Technique needed to notify of low memory condition during runtime #1379
Replies: 17 comments
-
Posted at 2020-03-27 by @gfwilliams
I guarantee this is not what's happening in JS.
http://www.espruino.com/Reference#l_E_errorFlag It'll get called when Espruino's had some difficulty allocating memory. It may not have 100% failed at that point, but it's got close. However, if you have problems even without that and you HAVEN'T seen any |
Beta Was this translation helpful? Give feedback.
-
Posted at 2020-03-27 by Robin Fri 2020.03.27 Thank you @gfwilliams for the reply.
I can assure you that after running a setInterval that updated once a second, calling a log to console method, printing the contents of around twenty vars, worked for at least five minutes, then multiple errors such as the one in post #1 indicating 'undefined' started popping up. I attempted to print those vars from the command line Left-hand console side, same error. Doing a dump, and the defined var that is clearly seen on the Right-hand editor side, and the var is clearly there, that was uploaded. Doing a search both in the source using Notepad++ and within the WebIDE editor match. But now attempting to run a wrapper function that calls the console.log statements now won't even run, also providing the same error. So Espruino is informing us that it can't find the previously declared var either, otherwise it would just return =undefined when not assigned a value. I even performed a sanity check on the L.H. console side to see what error is seen when an attempt to view a known non declared var is entered and the same errror occurs. I never defined rrr so this is correct - and the same for the now missing var
I scrolled through the dump contents and the var that is defined in the code that was uploaded is no longer there. I'll copy the contents of the console to a text file and take a fresh look at both the dump and the output, along with running more tests tomorrow. I'm chicken to power down/try again, in fear of not being able to have this repeatable situation, be reproduceable. If your statement above is accurate, what other ideas might make a var disappear? I'll read over the errorFlag event tonight and play with it tomorrow. Maybe that will shed some light. > EDIT: This is what is shown just after the undefined errors start to occur:
The LOW_MEMORY is obvious, and the FIFO_FULL most likely occurs as the logging function throws the error, bypassing or delaying the ability to turn off a pulse train created by analogWrite and the corresponding setWatch fills quickly. |
Beta Was this translation helpful? Give feedback.
-
Posted at 2020-03-28 by @MaBecker
Can you please share build version and a code snippet. |
Beta Was this translation helpful? Give feedback.
-
Posted at 2020-03-28 by Robin Sat 2020.03.26
Build version is provided at the end of post #1 code file at post #12 link here Thank you @MaBecker for taking the time to read through this post, and your enthusiasm and curiosity to assist here. I purposely wrote the content and selected the title requesting a 'Technique' as I realized debugging this will be too time consuming to put anyone through. I also realized Gordon would understand that, as he had been assisting here in another thread I started a month ago, and wouldn't be available, (see post #9 there, below) until after the Bangle K.S. shipments. I kept the request terse, knowing that I could move forward with a simple technique as reducing the demand on memory, may and most likely allow me to see this through to completion.
To 'whet your whistle' I discovered some cool stuff using PPI that would make for a great multi-part tutorial to put the Javascript haters at bay, demonstrating near one-for-one match with that other 'C' programmed ubiquitous device. The last code file in post #12 above worked as I described above in post #1 here, great until I started adding functions that called multiple console.log statements rendering var contents to the WebIDE console. I knew I was running short on memory in the other thread, and continuing was going to be a challenge. I've also toyed with whether I'd be better off attempting to teach others to use this tutorial in order to find a solution, compared with just pluggin' along knowing it's likely a memory issue. My realization is that I would spend more time attempting to convey concepts and use others time that will be needed with Bangle, than just continuing performing tests with Gordon's new suggestion. The code file is over 1500 lines of code and comments, and is using 90%+ of available memory. To move forward, the six bulleted items at the end of post #12 need more needed attention at the moment, in order for me to complete this tutorial. Adding Gordon's suggestion, and seeking solutions to pare down the existing file size is trivial at this point. Providing assistance in solving those items would be a more prudent use of your time, should you be able to spare it, and thank you. Should I not find a suitable solution within a week, I'll post the entire code file as it sits. |
Beta Was this translation helpful? Give feedback.
-
Posted at 2020-03-28 by Robin Sat 2020.03.28
If I understand the above, I don't appear to have problems as nothing was being displayed, and I 'hadn't' seen a Okay, worked all day on this. While I have been extra careful over the last two years to make sure all code is inside separate functions so no execution occurs during upload, I've double checked and verified this is the case, along with making sure nothing other than several vars are initialized, only a function call to display a shortcut list of function call names is rendered. I ripped out many tens of lines of code to get the file size waaay down, so that there were around 600-700 JSVARS available, so as not to run into the ~100 JSVAR minimum that I have read elsewhere that must not be exceeded. I issue a I even unplugged the MDBT42Q, in case something corrupt remained, but is consistent, despite nothing I am intentionally doing would be causing a 'FIFO_FULL' error:
This error is consitent with what I witnessed yesterday, post #3 with the significantly larger file but during runtime. So, maybe that 'FIFO_FULL' flag has always been there, as I wasn't aware to even detect that until the suggestion in post #2. What is really puzzling is the now 'LOW_MEMORY' flag, despite only using 70% of memory. This actually ran several days ago with only ~200 JSVARS remaining, so with an additional 400 free now, shouldn't be an issue. I upload the code file from the Right-hand editor side, and the following is observed, and entering the command, flags can be seen that are set:
While creating the content for this post, I entered
The new question, what is causing the FIFO_FULL error when just uploading code? I'm not seeing the MEMORY error and there are 600+ JSVARS available, so there shouldn't be a memory issue, correct?
What is the trip point for low memory as I've stripped 30%+ and still get the flag on upload:
Note that running a forced garbage collection |
Beta Was this translation helpful? Give feedback.
-
Posted at 2020-03-29 by Robin Sun 2020.03.29 The following is 100% reproduceable, just uploading the code.
I performed the following three times as I couldn't believe my luck finding a repeatable condition. I've gutted nearly 1/2 of code file lines, primarily external comment blocks, embedded comment lines within functions, and any code snippets that weren't needed to run a simple test. It shouldn't be necessary to wire external pins as code no longer functions, although I haven't tested. To get to this final file, the goal of the project no longer works, and many features can no longer be tested. That's okay at this point, as I've found a 100% reporoduceable situation. It appears that whatever table mechanism that references internal functions by name, becomes corrupt and therefore unaccessible, just by uploading! 3x I've powered off/on the device. I've closed/opened the WebIDE. I haven't rebooted Windows10 yet, but will do soon as I also search for, and try other lint tools. I added some simple function wrappers to avoid having to type long commands.
I load the code file from disk. I upload to the MDBT42Q. It takes twenty seconds to settle down before the second > prompt is visible. At this point, an attempt to run function dpu() results in:
Typing dump() or searching within the WebIDE editor will find that function at L200 I've run every combination of the following, and ther results are approximately the same. Running a garbage collection does clear the 'LOW_MEMORY' flag and frees up 6 JSVARS. Repeatable. Here is a sample: Even with 30%+ free JSVARS, no MEMORY error, but a hidden LOW_MEMORY flag is set:
Attempting to run a function that is visible on the code side and within a dump() results in:
Performing a dump() will clearly show the function listed in tact L367 around the first quarter of the dump, as everything does not match the source file chronological order. I'm posting this here now, as this ran a week ago before I started adding more comments and additional accessor functions. I'll search for other lint checkers, and continue testing tomorrow with a fresh start.
Butchered code file to get the repeatable error, so withold the comments on format and style. ;-) L367 in dump20200328p0807dpuTEST3.txt file is the dump showing function exists Attachments: |
Beta Was this translation helpful? Give feedback.
-
Posted at 2020-03-29 by Robin Sun 2020.03.29 Fresh start. Power on MDBT42Q. Start WebIDE. Same code file where I left off. This is starting to appear to be a parsing issue, or when data chunks are sent to the MDBT42Q, they are not being received as they were sent. Now a new error appears:
dump() shows that line L7 is there, fifth inside the help() function:
If one inspects around L730 in the source file, it can be seen the correct syntax is present. The dump is showing that [ console.log( " ] is missing L8 from what was originally there.
When I attempt to view the console output: WebIDE :: Settings >> Console
I note that data is sent by the WebIDE in small chunks. Presumeably the device sends back similar manageable small chunks in response to the dump() request. I've tried to capture the outbound file, but just not quick enough to open the console output, before it is pushed off the top. As we (viewers) see the errors within the WebIDE, and this device is wireless, it might be that Espruino running on the device detects an issue in memory, and then reports that to the WebIDE. This would mean that memory on the device is corrupt, and not a translation issue sending chars to the WebIDE that might become corrupt within the WebIDE memory space, during the transfer process. Does Espruino perform a checksum test on each line of chars that are sent over BT to validate what is received is what was sent? If yes, then this is more likely a parsing/re-assembly issue. |
Beta Was this translation helpful? Give feedback.
-
Posted at 2020-03-29 by Robin Sun 2020.03.29 two hours later This time a possible parsing issue. I stripped out more comments, now making 800+ JSVARS available. I put back in a function that just prints to the console, but on startup am now faced with a 'FIFO_FULL' error. I commented out that L1248 df() function call, and a new error popped up, but that made sense, as I had stripped the setWatch and inlineC section from Test3, under the assumption that maybe there was a parsing issue with the 'C' code. See Test4
So, I inserted the setWatch and inlineC back in. L225 thru L 244 in Test4a Now the error is cleared. Note that this pushes the entire balance of the file downward, by around twenty lines, as the file now has more code lines. On upload, the error in post #8 is now gone! Performing a dump also confirms this. L996 dump20200329a1109Test4aFORUM.txt This now points to a parsing issue. Attachments: |
Beta Was this translation helpful? Give feedback.
-
Posted at 2020-03-30 by @gfwilliams Ok, so taking a very quick look at your code, what you're doing is:
Given Espruino's execution speed this, all by itself, is going to be quite a stretch. When you add a watch, the events generated when a pin changes state go into the FIFO (the same one used for uploading code). If you don't handle those quickly enough then you get FIFO_FULL. So... If that code ever gets enabled while you are uploading then it'll interfere with the code upload. If you had happened to save the code to flash with 'always run at boot' then it'd really mess things up. Or there's a possibility that if it is running, the upload of new code will be affected Also, just so you know, if you're trying to save memory then adding 'help' functions like this really won't help:
If you absolutely feel you need them then you could use templated Strings, which will be a lot easier to write, and will use less memory:
|
Beta Was this translation helpful? Give feedback.
-
Posted at 2020-03-30 by Robin Mon 2020.03.30 This narrative is in response to this answer, but is included here as it contains follow up example output pertinent to the ongoing issue:
I haven't seen a flaky memory cell in twenty years, so I thought unlikely either. But, I had a situation yesterday that nearly identically mirrored the one that caused me to post this thread in the first place. Remember I had a working code file ~2000+ lines for over a week, running with around 200-300 JsVars free. It was close to being stamped 'done' but needed some minor code cleanup, and the addition of console help. In post #9 I mentioned I inserted back in a small snippet, expanding the file size, and miraculously the dump errors ceased. So I happily continued for around four hours. Then, Whammo! a similar error response then appeared.
which is eerily similar to the original
which could not have been true, as I just uploaded the code file with the var definition there.
Now doing a sub-string search I was able to locate why Espruino is reporting the error, as that var IS NO LONGER THERE!
After initialization, not only does the content of the var location change, the name of the var changes also!! Using: I looked up the offending char
but the insight doesn't occur until converted to it's binary equivalent:
I opened this thread. Then when on a hunch I wondered if RAM/hardware was a problem, I posted the link above for an exhaustive test routine.
and found on two separate occassions, but only archive the dump for one:
dump
and looking those up
converted to it's binary equivalent:
It is interesting to note that the changing char is in the fifth location in from the margin, and each discovered case, one and only one bit (but not the same one) is flipping. I inquired about how dump() actually works at the end of post #8, and have re-inserted it here: last two pp of post #8 As we (viewers) see the errors within the WebIDE, and this device is wireless, it might be that Espruino running on the device detects an issue in memory, and then reports that to the WebIDE. This would mean that memory on the device is corrupt, and not a translation issue sending chars to the WebIDE that might become corrupt within the WebIDE memory space, during the transfer process. Does Espruino perform a checksum test on each line of chars that are sent over BT to validate what is received is what was sent? If yes, then this is more likely a parsing/re-assembly issue. Knowing how dump works is the clue to solving this predicament. Memory is changing at run time, as I have inspected *(accurate)* a dump, just after upload, checked available memory, observed the var from the command line, started the setInterval and then observed the error and re-verifying the var is subsequently changing. I now take issue with the statement from post #2 > 'I guarantee this is not what's happening in JS' as here are now three concrete examples. |
Beta Was this translation helpful? Give feedback.
-
Posted at 2020-03-31 by Robin Mon 2020.03.30 response to post #10 Thanks for taking a quick peek @gfwilliams.
Yes understood from a previous post that suggested a limit of ~100 and I'm well below that with sending out just six pulses at this point.
This one might agree with an observation I made with PPI that peripherals stay enabled, and a means to disable would be nice.
Thanks for the tip/reminder. Purposely not using save() and not using minification to rule those out.
I understand, but mostly needed to assist in debug at this point as I'm not able to recall quickly all the variants that are needed. I tried the Template Literals approach, and would be great if it worked as in that suggestion, but it isn't possible to vertically space for legibility, even using an embedded newline char
becomes just:
and not what we intended. Had to resort back to the tried and true for now to be able to read legibly. Although @oscar indicated some success, there wasn't a definitive clue that setWatch was mastered
@barry_b_benson hasn't responded as to the success with a 300msec watch
I had issues that weren't fully resolved six months ago
and then again with the issues with PPI and this thread
I only found one reference to PPI and like myself, @tomws unsuccessful in a solution
While the simple examples presented seem to open the door, in practical use, not many have explored this feature, so those issues that I have uncovered most likely hadn't been discovered yet. |
Beta Was this translation helpful? Give feedback.
-
Posted at 2020-03-31 by @gfwilliams
I have no idea what you're doing, but:
prints as:
as you'd expect. Just tried it and it's perfect. Thousands of people use setWatch every day - for buttons - and it's fine. So you're obviously doing something different here...
If you're using |
Beta Was this translation helpful? Give feedback.
-
Posted at 2020-03-31 by Robin Tue 2020.03.31
Could it be a notepad++ to WebIDE import that strips out the newline? What is it supposed to be? While that block works here in the forum, it isn't within the WebIDE. I copy-n-pasted directly from the section from #10 post in both the editor and console sides. I'll break out the hex editor today.
And the reason I stated in the other PPI thread that as there aren't many uisng MDBT42Q that the error(s) is a result of setWatch and underlying channel PPI stuff.
If that were the case, I'd be seing 'FIFO_FULL' error flag, which is not occurring. While the tutorial will show all this, the other gated pulse is used to turn on/off that write output. I expect by duration calculation and can see and have verified six on a scope. One reason I slowed the pulses down when the errors started to occur, to make sure pulse edges caught by setWatch were not going over the ~100 detection limit. |
Beta Was this translation helpful? Give feedback.
-
Posted at 2020-03-31 by @gfwilliams
Post #9:
Sorry, I'm super busy at the moment and I don't have time to go further with this at the moment. Maybe someone else can jump in |
Beta Was this translation helpful? Give feedback.
-
Posted at 2020-03-31 by Robin Tue 2020.03.31 ref to 'FIFO_FULL' snippet in post #15 The reference to post #9 did occur there, but that was three days and more than ten new file cleanup attempts. In my mind, I was thinking 'CALLBACK' flag and knew I had posted, but as can be seen, not in this thread. It was in fact at:
So I now understand the response as I hadn't placed that content here, although I knew I had posted it.
Yes please, any assistance would be greatly appreciated. Priority at this moment:
In the mean time, I'll attempt to rip out *ALL* comments and manage two files, as painful as that will be, and I'll look into uploading not changing code to flash, run that from there and still edit using RAM to continue.
works on your PC ;-) So, which WebIDE and OS was this done? Four tests below for me on Windows10 fail.
Template Literal example post #10 and post #13 is not rendering as such with the
It can be observed from the dump, that the newline char isn't preserved within the function itself, and thus when attempted to then render, doesn't include the blank line as desired. Not seeing blank lines as in that post #13 suggestion:
Tested with both a nRF52 MDBT42Q and can see the newline char is sent:
and on a STM32 Pico with identical results. Also tested with both the native app and the online IDE No minification Test using native app Web IDE version 0.70.6 > EDIT: Thr 20200402 - *(blank lines)* above To be worked on see post #2: > http://forum.espruino.com/comments/15186872/ -------------------------------------------- **Attachments:** |
Beta Was this translation helpful? Give feedback.
-
Posted at 2020-04-03 by Robin Fri 2020.04.03 Finally have made some progress! I have discovered 'WHAT' is going on, but it isn't quite clear 'WHY' the output is behaving the way it is. At the moment, it appears to be how Javascript works, and doesn't appear to be related to the number of pulses seen by setWatch. On a discovery made while using PPI, a hunch I have is to do with the prescaler, as certain frequencies produce very bizarre output data values. I'll be spending the next few days collecting data ouptut, then creating functions to present that data for analysis. We'll then have the means to test known values and observe both hardware and software output.
|
Beta Was this translation helpful? Give feedback.
-
Posted at 2020-04-06 by Robin Mon 2020.04.06 Sidebar: flag 'blocksize : Size of a block (variable) in bytes' doesn't appear in results or returns 'undefined' if direct access is attempted: process.memory().blocksize Three simple answer questions, no code analysis required. . . . There appears to be an anomaly issuing a gabage collection command.
At this point, if I attempt to copy-n-paste a function into the console Left-hand side of the WebIDE, one of two conditions typically occur. The first is that upload is successful, but then are greeted with:
and no further keystrokes can be entered, or worst case, the function isn't completly copied, thereby locking up the WebIDE. Reviewing the flag detail, *link above*
Knowing that JsVars are maintained by a table of linked references, and realizing I am uploading thirty lines of dense console.log output, I used the following to understand exactly what the copy-n-paste was doing, regarding memory usage:
Upon upload complete, I'm greeted with 'Execution Interrupted' and no more keystrokes may be entered. This means that the history content is not getting removed before lockup. Only left with: Disconnect device, power down, power up, reconnect and re-upload. Annoying. Q1: As the 'History' flag indicates that it's value is included in the 'Free' JsVars count, does this mean that the total 'Free' value, is in fact not a true memory available indicator, e.g. 'Memory that is available to be used' is in fact not what the user nor what Espruino actually has available for operations, but must be adjusted by subtracting out the history value? Should that be true, maybe an option 'Avail' or 'Usable' representing 'Free' minus 'History' which is more intuitive? Is there a way to run the garbage collector to just remove the history? While analyzing the gabage collection detail, I discovered another quirk that is also gobbling up memory. My code file is 28K in size, and takes about 30 seconds to upload over BLE. Once complete, I can inspect and see that 2000 JsVars are being used. As we know:
BT sends out chunks of around 20 chars: WebIDE >> Settings >> Console
which shows that around 22 chars max are transfered on each push. Knowing it takes about 30 seconds to upload, we are transfering roughly 1000 chars / sec This seems rather slow, 8000bps, one tenth of achievable. A rather exhaustive and informative read on how complex BLE really is!! 'throughput may theoretically reach the limit of ~230 kbps, but actual applications analyzed in this review show throughputs limited to ~100 kbps; the maximum reachable range is strictly dependent on the radio power,' Ahhh, in reading over that page, found Section 3 Table 1 that payload is 20 bytes! Q2: What is the transfer speed of BLE packets uisng the WebIDE? As I realized that console.log statements are eating up memory, and while the WebIDE Template Literal backburner fix is underway, I decided to re-write those functions writing to memory for later analysis. But a curious thing still happened, yep, still running out of memory. This time though, for a completely different reason. I was attempting to write a JSON name:value string to each memory location, but that was still failing. So I stripped down to something easily understood.
Using E.getSizeOf() and ary.length continued to verify actual usage. Using a known value, in this case from getTime() we know we have a float, and a float takes eight bytes. Three for the JsVar ID and those eight should take 1 JsVar, which it does. I write exactly four floats to that array. Using the above, I am able to iterate over the array, and the length stays at 16. Now here is where it gets interesting. When I place the same code inside a setWatch(), under some conditions, unkown at this point the array mysteriously jumps in size, despite I never use an indexer that is out of range. I'm only iterating over the first four slots in the array. Some times, the array jumps by ten, sometimes it quadruples. I've even placed conditionals inside, along with console.assert() to absolutely make sure I'm not changing the indexer into that array. Yet, the array increases in size. It is almost as if the underlying PPI hardware continues to fire the setWatch, or the setWatch is responding to the underlying PPI and not the actual state at the pin as the scope sees it. I tried searching W3C, MDN, W3Schools and other sites to see if I could learn on the criteria for arrays. Years ago, it used to be an additional ten slots were added, but I can't locate under what conditions. Reading over:
and specifically a suggested section: Looking over the source:
I see several slice, join and length references. Q3: What is the criteria for Espruino to expand an array, and what increase % is used to make that determination? Where in source? |
Beta Was this translation helpful? Give feedback.
Uh oh!
There was an error while loading. Please reload this page.
-
Posted at 2020-03-27 by Robin
Fri 2020.03.27
I know this is a remaining JSVAR memory issue. I have a rather large app 2300 JSVARs with loads of
helper logging output.
It ran great until I started altering data sets. I started to notice intermittent errors, so started smattering code with try/catch blocks to see if I could catch errors. Minimal luck.
Today, I have a repeatable situation after an execution of a helper function that writes out ~20 consol.log() statements. A single manual invocation works great. Inside a setInterval however, started getting bizarre errors that are never caught by the try/catch blocks. After performing a dump() I can validate that this error does in fact show that previously defined vars are no longer there.
Memory is getting written over. In 'C' it's the dreaded missing null line terminator. Used to malloc heapfree etc.
Using process.memory().free I can determine the amount of JSVARs available before I execute a function, but what is the proper technique to discover a possible memory overrun before it occurs at runtime? Is there a method to know whether a function call is going to require massive memory overhead before the call?
Using a MDBT42Q breakout board
Beta Was this translation helpful? Give feedback.
All reactions