robhagemans / pcbasic

PC-BASIC - A free, cross-platform emulator for the GW-BASIC family of interpreters
http://www.pc-basic.org
Other
400 stars 48 forks source link

16.12: String temporaries overwrite permanent strings #49

Closed Danitegue closed 6 years ago

Danitegue commented 6 years ago

the function clear in pcbasic\basic\memory\memory.py, should clear all the non persistent variables after each session loop. It triggers the function _preserve_scalars in pcbasic\basic\memory\memory.py:

@contextmanager def _preserve_scalars(self, names, string_store): """Preserve COMMON variables."""

copy all variables that need to be preserved

    common = {name: self.scalars.get(name)
                for name in names if name in self.scalars}
    yield
    for name, value in common.iteritems():
        if name[-1] == '$':

            #length, address = self.strings.copy_to(string_store, *value.to_pointer()) #Original
            #value = self.values.new_string().from_pointer(length, address) #Original

            #Issue: The value of the strings appears as 'detached' after the copy to string_store, and therefore they are not preserved correctly. This has to be fixed, if not the value is lost. Alternative:
            #1- Obtain the memory pointer and len of the actual value
            #2- Copy the value to the string_store, and obtain the new length and new memory address in this new store.
            #3- Update the value info with the new memory address

            length1, address1 = value.to_pointer()
            length2, address2 = self.strings.copy_to(string_store, length=length1,address=address1)
            value =self.values.from_str_at(string_store._strings[address2], address2)

        self.scalars.set(name, value)

is this solution good enough? In this reassignment, what is the goal?, I understand that it is copying only the values of the persistent strings to new memory addresses, update the binding value-address, and then clearing all the old values and addresses that should not be persistent, not?.

Danitegue commented 6 years ago

Example of the original behavior:

\memory\memory.py, Reset and clear variables: preserve_common= (set([]), set([])) , preserve_all= ALL , preserve_deftype= True

\memory\scalars.py, clear(), scalar variables cleant.

\memory\memory.py, _preserve_scalars, var: NO$ with value1: $[03e9fc '185'] to value2: $[034dfd < detached > ]

\memory\memory.py, _preserve_scalars, var: E$ with value1: $[04e5fd '.rtn'] to value2: $[0413fd < detached > ]

\memory\memory.py, _preserve_scalars, var: A$ with value1: $[00a3f6 ''] to value2: $[0002fb '']

robhagemans commented 6 years ago

Hi, thanks!

Could you please attach the BASIC code that triggers this? It seems to me the bug is at a deeper level. The way DataSegment.clear() works is that it constructs a new string space, copies the persistent string scalars first and arrays second, and then replaces the old string space with the new. The reason it does this is so that the new addressing aligns with GWBASIC.

I think in the code you propose the strings are copied into the old string space, and would then be overwritten further on in clear(). I am not sure why the existing code breaks though, I'd have to try first.

Danitegue commented 6 years ago

Yes of course. Here the code, is simply your original code but rewritten in this way:

def _preserve_scalars(self, names, string_store):
    """Preserve COMMON variables."""
    # copy all variables that need to be preserved
    common = {name: self.scalars.get(name)
                for name in names if name in self.scalars}
    yield
    for name, value in common.iteritems():
        if name[-1] == '$':

            #length, address = self.strings.copy_to(string_store, *value.to_pointer()) #Original code
            #value = self.values.new_string().from_pointer(length, address) #Original code               
            length1, address1 = value.to_pointer()
            length2, address2 = self.strings.copy_to(string_store, length1,address1)
            value2 = self.values.new_string().from_pointer(length2, address2)  #Here is the problem.

            if str(name) in ['E$','A$','NO$']:
                print '\memory\memory.py, _preserve_scalars, var:', str(name),' with value1:', str(value), ' to value2:', str(value2)
            value=value2
        self.scalars.set(name, value)

Yes my solution is not good enough... since I still cannot run properly the program. It hangs sooner or later because of an aleatory variable that has changed its value...

Could it be happening by a problem with the --max-memory=65535 or -s=128 options? I have tried to change both but is still giving the same problems.

capture

robhagemans commented 6 years ago

Hi, sorry, what I mean is could you attach the BASIC program where this problem occurs?

If I understand you correctly you are trying to run a BASIC program with PC-BASIC and strings do not behave as expected after CLEAR, which seems to be due to some big in the Python code where they become detached, and your Python code aims to fix this. If I have the program it's much easier for me to find out what is happening and how to solve it.

If I've misunderstood the problem you are raising, let me know

robhagemans commented 6 years ago

Also, the print statement in your Python code won't show the string values, as at that point the values are temporarily stored in string_store rather than in the usual location. They'll be back to normal further down in the clear() function where the string space is being replaced with the temporary store we've created here.

Danitegue commented 6 years ago

Hello Rob, sorry for the delay in the answer.

The Basic program is a little bit complex to attach, since it needs a lot of extra files (routines, schedules, calibration files, and configuration files that has to be configured for the paths of all the previous ones). But I have prepared a pre-configured repository in which there are all the needed files, some launchers, and a quick tutorial to make it work in both, an ansi interface, or to debug it into pycharm using pygame interface: PCBasic_Brewer_Repo

The program can run in offline mode, or nobrew mode (no instrument connected, no com ports needed at all), using the pcbasic_brewer/Launcher_brewer185_nobrew.bat launcher.

Yes you understood correctly, the strings do not behave as expected since some of them are being detached in the memory.py clear function. (more concretely they become detached in the self._preserve_scalars(preserve_sc, new_strings) function which is called inside the clear function.

I initially proposed a solution but it didn't work, I'm still trying to understand the memory scheme of the interpreter.

As an example, just after the program is loaded, it is assigned to the variable E$ the string ".rtn" (Which is used to build the filenames of the routines files that are going to be loaded later). As soon as the clear function is executed, that variable appears as detached, and therefore you cannot run any routine when the program finishes its initialization because it cannot find the files due to wrong filenames.

robhagemans commented 6 years ago

Hi, I don't think I'm going to be able to set up the whole project, unfortunately I don't have a lot of time at the moment... If there's a smaller program that does just the strings and shows the issue in an unmodified PC-BASIC, perhaps I can look at that? Note that it's expected that these variables appear as 'detached' while in the _preserve_scalars function, but they should not be detached afterwards anymore.

Strings are effectively pointers to a location in a string store, which emulates a region of data memory in GW-BASIC. During the function the store is being rewritten but the pointer has not yet been updated, so it will appear as detached in a Python print statement and in any debugger that calls the __str__ function on the string object to show its contents.

Does this arise in a CHAIN statement?

Danitegue commented 6 years ago

Hello Rob.

At a certain point of my program, some variables (not all) were changing its values by no apparent reason. Some of them appeared as detached, and some of them were receiving the values of other newer variables. At a first point I thought it was due a wrong preserve_scalars function.

But then, after researching a little bit and having into account your notes, I understood that as you have explained the variables must be detached, until the string space is re-built with the string store, and then the pointers are re-assigned. So, my problem has nothing to do with this preserve_scalars function...

I have traced this problem until strings.py, store function. I don't know why, the temporal string results while parsing a BASIC line are being stored into already occupied memory positions.

Example of a small program, to run in your original pcbasic version:

10 REM PC-BASIC test 20 REM RIGHT$ function 30 ON ERROR GOTO 10010 40 ICF$="icf06617" 50 YE%=17 60 DA%=5 70 YF$=RIGHT$(STR$(YE%+100),2) 9999 END 10010 RESUME NEXT

With this logging line added to the strings.py, store function, we can print out the problem:

def store(self, in_str, address=None):
    """Store a new string and return the string pointer."""
    length = len(in_str)
    # don't store overlong strings
    if length > 255:
        raise error.RunError(error.STRING_TOO_LONG)
    if address is None:
        # reserve string space; collect garbage if necessary
        self._memory.check_free(length, error.OUT_OF_STRING_SPACE)
        # find new string address
        self.current -= length
        address = self.current + 1
    # don't store empty strings
    if length > 0:
        **logging.info('strings.py, store, storing:'+str(in_str)+' into address:'+str(address))**
        # copy and convert to bytearray
        self._strings[address] = bytearray(in_str)
    return length, address

This is the result:

INFO: strings.py, store, storing:icf06617 into address:4785 INFO: strings.py, store, storing: 117 into address:65017 INFO: strings.py, store, storing:17 into address:65015

So, this means, when parsing the line: RIGHT$(STR$(YE%+100),2), the first parsed temporal result STR$(YE%+100) = ' 117' is being stored into a slot of the strings memory (65017). The second temporal result RIGHT$(' 117')='17' is being stored into another different slot of the strings memory (65015). Each new temporal result is given a lower index in the memory 65017 > 65015 > ... . The value of the first string var ICF$, I don't know why, is being stored is in a lower index than these others (4785). The problem come when we have a big program, with a lot of strings already stored in the lower indexes, and the temporal strings results are stored from higher to lower memory slots until they overwrite already occupied memory slots.

Possible solutions, from a very early point of view: -Make the string variables being written from higher to lower indexes (always, not only the temporals). -Use a different strings memory space for temporal parse results. -Improve the memory address assignment of the strings.py store function, in order not to take already occupied memory positions.

What do you think?

Regards, and happy christmas!

TEST3.zip

robhagemans commented 6 years ago

Hi again, and thanks for the test code and explanation! If I understand it correctly the problem arises when storing a lot of temporary string variables; in this case permanent string variables are being overwritten. That shouldn't happen; if there really is no more space then an error should arise instead (either Out of memory or String formula too complex, I'd have to check with GW-BASIC what happens there).

The addressing of temporary strings follows what happens in GW-BASIC, or at least is intended to do so, which means the first two solutions aren't really in line with the idea behind PC-BASIC, which is to be as close a replica of GW-BASIC as possible. (Of course, you could implement this in a derived version, but it may be difficult to maintain if something changes to the main version of PC-BASIC).

There clearly is a problem with the store function if it overwrites existing strings with temporaries - I just have to find out what exactly GW-BASIC does here...

Danitegue commented 6 years ago

Thanks a lot for your interest.

A question. In the header of the memory.py file, "Data Segment Map", you wrote this: ... 4720+c v scalar variables 4720+c+v a array variables 65020-s top of string space ... Following this, in my test code, shouldn't the first string be stored at the "top of string space" instead of being stored in the "scalar variables" field? (INFO: strings.py, store, storing:icf06617 into address:4785).

In other hand: Here are 3 pictures of the strings space of my large program, just at the moment in which the ICF$[64786] string is going to be overwritten with the result of the YF$=RIGHT$(STR$(YE%+100),2) (='17'). In these pictures we can see 2 things. The first thing is that the strings memory is not full at this point. The second is that there are other strings (non temporals) already stored in lower memory positions than the current self.current pointer (=64786). So, perhaps the self.current pointer was reset or lost at any moment, or simply it was not re-initialized after clearing non preserved strings. I will research on it...

capture0 capture1 capture2

robhagemans commented 6 years ago

The reason ICF$ is at such a low address is that it's a string literal - it's given directly in the program code as above: 40 ICF$="icf06617"

The string pointer for ICF$ initially points directly to program memory (starting at 4717, apparently the first character of the string is the 68th byte of the program). It's only moved to string space if the string is changed. Variable space starts at 4020+c where c is the length of the program in bytes.

I'm not sure what's going on with the temporaries yet.

robhagemans commented 6 years ago

It looks like the StringSpace.rebuild() method may not be updating the .current pointer. Are you using CHAIN and COMMON in your programs? That seems to be the only place where this is being called as far as I can see.

robhagemans commented 6 years ago

Hi, have a look at commit 5db5deb - it's just a single extra line. Does this solve the problem?

Danitegue commented 6 years ago

Yesss and no... of course this line is a must, now the temporals are stored in a sorted way, from higher to lower pointers, much better.

This means that now in my large program the ICF$ var is not overwritten anymore. But unfortunately something more is happening a little bit after.

I'm having now a KeyError, in the strings.py, _retrieve function.

It is trying to retrieve the value of a non existing temporal string with supposed length=4. So in the line

return bytearray() if length == 0 else self._strings[address]

it breaks.

Here the traceback of the error: File "C:\PCBasic_Brewer_Repo\pcbasic_brewer\pcbasic\main.py", line 185, in run_session session.execute(cmd) File "C:\PCBasic_Brewer_Repo\pcbasic_brewer\pcbasic\basic\session.py", line 250, in execute self.interpreter.loop() File "C:\PCBasic_Brewer_Repo\pcbasic_brewer\pcbasic\basic\interpreter.py", line 111, in loop self.parse() File "C:\PCBasic_Brewer_Repo\pcbasic_brewer\pcbasic\basic\interpreter.py", line 97, in parse self.parser.parse_statement(ins) File "C:\PCBasic_Brewer_Repo\pcbasic_brewer\pcbasic\basic\parser\statements.py", line 90, in parse_statement self._callbacksc File "C:\PCBasic_Brewer_Repo\pcbasicbrewer\pcbasic\basic\session.py", line 611, in chain self._clear_all(preserve_common=commons, preserve_all=common_all, preserve_deftype=merge) File "C:\PCBasic_Brewer_Repo\pcbasic_brewer\pcbasic\basic\session.py", line 455, in _clear_all self.memory.clear(preserve_common, preserve_all, preserve_deftype) File "C:\PCBasic_Brewer_Repo\pcbasic_brewer\pcbasic\basic\memory\memory.py", line 150, in clear self.scalars.clear() File "C:\Users\DS_Pandora\Anaconda2\lib\contextlib.py", line 24, in exit self.gen.next() File "C:\PCBasic_Brewer_Repo\pcbasic_brewer\pcbasic\basic\memory\memory.py", line 202, in _preserve_scalars length2, address2 = self.strings.copy_to(string_store, length1,address1) File "C:\PCBasic_Brewer_Repo\pcbasic_brewer\pcbasic\basic\values\strings.py", line 176, in copy_to string_to_copy=self.view(length, address).tobytes() File "C:\PCBasic_Brewer_Repo\pcbasic_brewer\pcbasic\basic\values\strings.py", line 198, in view return memoryview(self._retrieve(length, address)) File "C:\PCBasic_Brewer_Repo\pcbasic_brewer\pcbasic\basic\values\strings.py", line 188, in _retrieve return bytearray() if length == 0 else self._strings[address] KeyError: 64697

I will research a little bit more on it, I have to look what is the BASIC program doing at this point. Any idea of how to print out the actual Basic code line number, for making the debugging process quicker?

The program is using CHAIN MERGE commands for every time that a new instrument routine is loaded. But I have not found any COMMON in the Basic code.

El 27/12/2017 16:54, "Rob Hagemans" notifications@github.com escribió:

Hi, have a look at commit 5db5deb https://github.com/robhagemans/pcbasic/commit/5db5debb74e41ff9017a1d3e66c60390d21f1ccc

  • it's just a single extra line. Does this solve the problem?

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub https://github.com/robhagemans/pcbasic/issues/49#issuecomment-354142158, or mute the thread https://github.com/notifications/unsubscribe-auth/AYutGAsGlXVIguAj-ZP3hkGf5QyngoQEks5tEnYrgaJpZM4QsTNJ .

robhagemans commented 6 years ago

Hi,

Looks like some strings don't get copied in the CHAIN MERGE even though they should. That's a bit odd...

Any idea of how to print out the actual Basic code line number, for making the debugging process quicker?

Try the --debug command-line option. This enables an additional statement _DEBUG (note the preceding underscore) which works together with some Python functions in debug.py that do the kind of things you need. For example, this will trace your program flow and the value of A$:

_DEBUG "trace(); watch('A$');"

Note that all output goes to the command-line window from which you've started PC-BASIC, though you could probably re-route it to a log file.

There are some more debugging utilities in debug.py, it should also be fairly easy to add some (e.g. to show the address of a string).

robhagemans commented 6 years ago

I've made a few more fixes relating to string literals, CHAIN and garbage collection. I don't know if this fixes your issue, but it fixes a few other issues that I came across while researching this. These changesets are a bit bigger so it's possible that they break other things in your program (although they pass my tests)

Danitegue commented 6 years ago

Ok the latest changes until today are fine, now I have not more KeyErrors breaks, but they continue happening inexplicably!. We can notice it adding these lines to the retrieve function:

    def _retrieve(self, length, address):
        """Retrieve a string by its pointer."""
        # if string length == 0, return empty string
        if length != 0:
            try:
                strval=self._strings[address]
            except KeyError:
                logging.debug('strings.py, _retrieve, KeyError with address='+str(address)+', length='+str(length))
        return bytearray() if length == 0 else self._strings[address]

and we obtain: image

Is that usual?

Apart of that, now I'm having "Out of memory" breaks, in different points of the program, depending of the -s option. with -s=128 -> Out of memory in 31003 with -s=256 -> Out of memory in 12020 with -s=512 -> Out of memory in 3453

I will continue researching on that.

robhagemans commented 6 years ago

Hi, do I understand correctly that there no longer is a crash with KeyError but you continue to see them in your log file with the code above? That would happen if the program accesses string literals, which are not stored in string space.

However the pointer address seems oddly high for a string literals, suggesting your program is enormous (nearly 64K) and these strings are defined at the very end (maybe in a DATA declaration). Is that the case?

robhagemans commented 6 years ago

Hi @Danitegue,

I just realise that your logging code with catch and not re-throw the exception, so you won't see that it crashes - even if it does. Effectively it just logs and then ignores the error. Could you modify like this:

    def _retrieve(self, length, address):
        """Retrieve a string by its pointer."""
        # if string length == 0, return empty string
        if length != 0:
            try:
                strval=self._strings[address]
            except KeyError:
                logging.debug('strings.py, _retrieve, KeyError with address='+str(address)+', length='+str(length))
                raise
        return bytearray() if length == 0 else self._strings[address]

and check if it now crashes? If so, could you post the stack trace and error message? Thanks!

EDIT: sorry, please ignore. The last line would raise the exception even if it's caught before.

I guess I just don't understand what you mean by "I have not more KeyErrors breaks, but they continue happening inexplicably" - could you please elaborate? In general, if the KeyErrors are caught somewhere in PC-BASIC then they aren't errors, some bit of code is just checking if a string is stored at a given address. The only thing is, the only place I'm aware that I'm catching exceptions from _retrieve is in collect_garbage in cases where strings are stored as literals in the code or in the FIELD record of a file, and that does not seem to agree with the memory addresses you show.

robhagemans commented 6 years ago

OK, I can reproduce the bug with this:

10 DIM A$(1000)
20 FOR I=1 TO 1000
30   A$(I) = STR$(I)
40 NEXT
50 B$ = "b"+"-string"            
60 PRINT FRE("")
70 ERASE A$
80 PRINT FRE("")
Danitegue commented 6 years ago

Hi Rob, sorry for the delay.

Yes the program is big. One of the motivations of my project is that the Brewer Instrument community is complaining because they have no more memory for doing bigger routines, and this makes difficult to do science with the instrument.

With "I have not more KeyErrors breaks, but they continue happening inexplicably", I only wanted to warn that with your latest improvements my program was not breaking anymore by KeyErrors, but, the logging messages were still being written (And this means, that the keys errors continue happening, but they does not break the program, I don't know why...)

I have updated the code up to your changes of today, and the key error re-appeared, and it is breaking the program again. Here the trace:

Exception in thread Thread-1: Traceback (most recent call last): File "C:\Users\DS_Pandora\Anaconda2\lib\threading.py", line 801, in bootstrap_inner self.run() File "C:\Users\DS_Pandora\Anaconda2\lib\threading.py", line 754, in run self.target(*self.args, **self.kwargs) File "C:\PCBasic_Brewer_Repo\pcbasic\pcbasic\main.py", line 164, in run_session session.execute(cmd) File "C:\PCBasic_Brewer_Repo\pcbasic\pcbasic\basic\session.py", line 250, in execute self.interpreter.loop() File "C:\PCBasic_Brewer_Repo\pcbasic\pcbasic\basic\interpreter.py", line 107, in loop self.parse() File "C:\PCBasic_Brewer_Repo\pcbasic\pcbasic\basic\interpreter.py", line 96, in parse self.parser.parse_statement(ins) File "C:\PCBasic_Brewer_Repo\pcbasic\pcbasic\basic\parser\statements.py", line 90, in parse_statement self._callbacksc File "C:\PCBasic_BrewerRepo\pcbasic\pcbasic\basic\session.py", line 609, in chain self._clear_all(preserve_functions=common_all, preserve_base=(commons or common_all), preserve_deftype=merge) File "C:\Users\DS_Pandora\Anaconda2\lib\contextlib.py", line 24, in exit self.gen.next() File "C:\PCBasic_Brewer_Repo\pcbasic\pcbasic\basic\memory\memory.py", line 185, in preserve_commons self.scalars.set(name, value) File "C:\PCBasic_Brewer_Repo\pcbasic\pcbasic\basic\memory\scalars.py", line 52, in set self._memory.check_free(size, error.OUT_OF_MEMORY) File "C:\PCBasic_Brewer_Repo\pcbasic\pcbasic\basic\memory\memory.py", line 205, in check_free self._collect_garbage() File "C:\PCBasic_Brewer_Repo\pcbasic\pcbasic\basic\memory\memory.py", line 200, in _collect_garbage self.strings.collect_garbage(string_ptrs) File "C:\PCBasic_Brewer_Repo\pcbasic\pcbasic\basic\values\strings.py", line 255, in collect_garbage string_list.append((view, addr, self._retrieve(length, addr))) File "C:\PCBasic_Brewer_Repo\pcbasic\pcbasic\basic\values\strings.py", line 181, in _retrieve return bytearray() if length == 0 else self._strings[address] KeyError: 64277

Here the log file info: ERROR: String not found in string space when collecting garbage: fb15

I append also the log file of my pcbasic_brewer version, which has also your latest improvements up today, but with logging messages of all the memory movements, perhaps it can give a clue of what is happening. Is curious to see it with notepad++ showing all characters, some null characters are being written in the string space.

pcbasic_brewer_log.txt

Say me If I can help you in any way,

regards

robhagemans commented 6 years ago

Hi, thanks for that. I think I've found the problem to be with temporary string handling during garbage collection. I'm looking into a further fix at the moment - but it requires some rewriting of code. Thanks for your help on this by the way, it's been key to finding precisely what was wrong.

For clarity, are you still getting the KeyErrors even including the three commits shown above your last post? (in particular 50e3c3c)? Because that fix removes the crash in my test program.

What has to be frustrating for your purposes is that the memory limitations your users complain about are caused by PC-BASIC aiming to replicate GW-BASIC as closely as possible, including its memory model and the 16-bit address space etc. While that's necessary for some applications, it probably isn't for you. If you don't need to POKE, PEEK and VARPTR into data memory, and are not too fussy about some edge cases of string handling, you could probably do away with much of the memory emulation (or at least that in strings.py) altogether. You'd need to take some care not to break FIELD and random-access files, unless you're confident you don't need any of those either.

A simple hack could be to decrease StringSpace.current by just 1 for each string that is stored, which would still give each string a unique address but use up the address space much more slowly. Or, more aggressively, you could do away with string pointers and just store everything as a Python string in the String object (but that would definitely break FIELD, LSET and the likes).

Similarly, if you don't need to PEEK into the program code, there isn't really a need to map it into memory; you could make the address space used by the program available to more strings, and allow programs bigger than 64K in the bargain.

The problem for me is that these things would quite possibly break some other things in subtle ways; it would be less compatible with GW-BASIC so in that sense it would be a worse solution for me; and I would personally not have time to maintain a variant strings module. However, since you're maintaining a fork anyway, it may be worthwhile. The problem will be that later changes I make could perhaps not be compatible with the variant strings module, so it may be more difficult to merge them into your fork. But you may not need those changes anyway...

Danitegue commented 6 years ago

"For clarity, are you still getting the KeyErrors even including the three commits shown above your last post? (in particular 50e3c3c)? Because that fix removes the crash in my test program." -> Yes, I pulled all the modifications done on 2nd dec, including your commented commits.

Today I have discovered that only the option -s=512 makes the KeyError appear in both, your latest version and in my pcbasic_brewer version:

-With -s=128: No KeyError, a later out of memory happen, in line 31003. -> None is written in the log. -With -s=256: No KeyError, a later out of memory happen, in line 12020. -> None is written in the log. -With -s=512: a KeyError breaks the program -> This is written in the log: ERROR: String not found in string space when collecting garbage: fb15 (which is the problem I explained in the previous message)

Both out of memory lines are into an external file "HP.rtn", which is MERGEd CHAINed into the main.asc main program: ... 12020 X(1)=1:Y(1)=1:ERASE X,Y:DIM X(100),Y(100):MAX$="80":HP.ADJ=0 ... 31003 P=4:A(1,1)=1:TTT(1)=1:D(1)=1:W(1)=1:ZI#(1,1)=1:ERASE A,TTT,D,W,ZI# ...

Here the logs of my version, perhaps they can help: pcbasic_brewerlog-s128.txt pcbasic_brewerlog-s256.txt pcbasic_brewerlog-s512.txt

I can try to run your test code, to see if we can replicate this problem with the same options. Which of the files you added is the test code you would like to test? TEMPSTR1, 2, 3..?

Danitegue commented 6 years ago

Thanks for the recommendations for the memory "enlargement". I have to think a little bit how to proceed in that. Another solution I was thinking is to write the new instrument (large) routines in python, and then make pcbasic interpret them by one or other way. But this is a next step, first we need to make the original software work, then communicate with the instrument without breaks, and then this other stuff...

robhagemans commented 6 years ago

OK, thanks, that's useful!

The test I meant is GARBTEMP, which actually crashed before commit 50e3c3c. Some of the new TEMPSTR tests fail, but don't actually crash the interpreter - they fail because they still produce an output different from GW-BASIC, in that the memory addresses aren't the same. Which is less urgent to fix than a crash.

The OUT OF MEMORY errors may well be "correct" behaviour (from my point of view, that is: it's correct if it would also happen in GW-BASIC) - even if they worked in a previous version of PC-BASIC, it may be because that that version didn't properly map strings to memory. You can however get a few more free kilobytes if you set reserved-memory=0, so if you're not already doing that it may be worth a try.

It's useful to know that the errors still happen with -s=512, it may be that the larger space used for the file buffer isn't properly accounted for. I'll have a look.

Finding some way of writing new routines for the instrument in Python is probably a good idea, I imagine you're only using BASIC because there is a large body of existing code for it in BASIC. If you have routines to communicate with the insturment, it's probably much easier for people to write new 'business logic' in Python. It's already possible to call BASIC from Python using the Session class (I don't think I've documented this though).

I've been thinking about ways of calling Python code from BASIC but I've shied back from it so far as to me it would just be a 'cool gimmick' that's another distraction from the core functionality, and my main aim at the moment is to bring the development version (i.e. master branch) of PC-BASIC up to a level where I can replace the release version (release-15.08 branch), so that I can stop maintaining that branch, because it is a horrible mess. Unfortunately we're not yet there and development has been basically dormant for a year.

However, the way to do build in that functionality (I think) is to include extension statements/functions: there's functionality for that, which at present is only used for the _DEBUG statement. It would be relatively simple to include an extension statement to be used along the lines of:

_CALL "python_func", ARG%, ARG$

This example call would then call a python function, in a module that's somehow linked:

def python_func(arg0, arg1) 

and provide it with an int value to arg0 and a string value to arg1, etc. You'd also want an extension function (a little bit more work) which you could call like

 A = _CALL("python_func", ARG)

and which would actually be able to return a result to the BASIC program. It may even be possible to make these access the Session object so that you can freely mix Python and BASIC while maintaining the state of the interpreter, but who knows what trouble that would get you into :)

robhagemans commented 6 years ago

New test TEMPSTR4 reproduces the crash. This seems to happen because a garbage collection cycle gets trggered (due to low memory) in the middle of a string expression. The temporary strings in the expression get moved in string space; but they don't have their pointers updated, since those pointers are not yet stored in a scalar or array element.

robhagemans commented 6 years ago

Hi @Danitegue, I wondered if the most recent commits had removed the crashes on your side?

robhagemans commented 6 years ago

For the Python-calling extensions, I've coded up an experimental implementation in the new experimental branch implementing a _CALLP function and statement along the lines set out above - have a look. I'm not sure yet if I'm going to take this into the main branch but it may help you.

The extended-memory idea I'm pretty sure I won't be able to support in the main branch; however, it can be implemented with a simple patch that (I think) doesn't really break things: diff.

I haven't done a lot of testing on these but it might help you in the right direction...

robhagemans commented 6 years ago

Note that you can already use the Session class to run BASIC code from Python, along these lines:

import pcbasic

with pcbasic.Session(stdio=True) as s:
    s.execute('''
        10 a=5
        20 print a
        run
        print a
    ''')
    a = s.get_variable("A!")
print a

This is all undocumented, but if you look at session.py you'll get an idea of what's possible.

Danitegue commented 6 years ago

Hi Rob,

Thanks a lot for the indications for the memory extension and/or how to run BASIC code from a python function. I'm sure this is going to be very very useful for the next steps. I'm sure you and your program will appear in several scientific articles if we can make our program work on it.

Respect the actual problem, I think we have no luck for now. I have pulled all your commits up today, and I have these results using your master branch:

-Case 1, with -s=128: No KeyError, a later out of memory happen, in line 31003. -> None is written in the log.

-Case 2, with -s=256: No KeyError, a later out of memory happen, in line 12020. -> None is written in the log.

-Case 3, with -s=512: a KeyError breaks the program -> None is written in the log. (A difference found here, since in the last day test, it was logging this message: "ERROR: String not found in string space when collecting garbage: fb15", but is not happenning now)

This is the trace of the KeyError error:

Exception in thread Thread-1: Traceback (most recent call last): File "C:\Users\DS_Pandora\Anaconda2\lib\threading.py", line 801, in bootstrap_inner self.run() File "C:\Users\DS_Pandora\Anaconda2\lib\threading.py", line 754, in run self.target(*self.args, **self.kwargs) File "C:\PCBasic_Brewer_Repo\pcbasic\pcbasic\main.py", line 164, in run_session session.execute(cmd) File "C:\PCBasic_Brewer_Repo\pcbasic\pcbasic\basic\session.py", line 250, in execute self.interpreter.loop() File "C:\PCBasic_Brewer_Repo\pcbasic\pcbasic\basic\interpreter.py", line 107, in loop self.parse() File "C:\PCBasic_Brewer_Repo\pcbasic\pcbasic\basic\interpreter.py", line 96, in parse self.parser.parse_statement(ins) File "C:\PCBasic_Brewer_Repo\pcbasic\pcbasic\basic\parser\statements.py", line 90, in parse_statement self._callbacksc File "C:\PCBasic_BrewerRepo\pcbasic\pcbasic\basic\session.py", line 609, in chain self._clear_all(preserve_functions=common_all, preserve_base=(commons or common_all), preserve_deftype=merge) File "C:\Users\DS_Pandora\Anaconda2\lib\contextlib.py", line 24, in exit self.gen.next() File "C:\PCBasic_Brewer_Repo\pcbasic\pcbasic\basic\memory\memory.py", line 195, in preserve_commons self.scalars.set(name, value) File "C:\PCBasic_Brewer_Repo\pcbasic\pcbasic\basic\memory\scalars.py", line 54, in set self._memory.check_free(size, error.OUT_OF_MEMORY) File "C:\PCBasic_Brewer_Repo\pcbasic\pcbasic\basic\memory\memory.py", line 216, in check_free self._collect_garbage() File "C:\PCBasic_Brewer_Repo\pcbasic\pcbasic\basic\memory\memory.py", line 211, in _collect_garbage self.strings.collect_garbage(string_ptrs) File "C:\PCBasic_Brewer_Repo\pcbasic\pcbasic\basic\values\strings.py", line 258, in collect_garbage string_list.append((view, addr, self._retrieve(length, addr))) File "C:\PCBasic_Brewer_Repo\pcbasic\pcbasic\basic\values\strings.py", line 181, in _retrieve return bytearray() if length == 0 else self._strings[address] KeyError: 64277

Then, I have tested again, but adding your recommendation "--reserved-memory=0" in the launcher:

-Case 4, with -s=128 and --reserved-memory=0: The program can continue a little bit more than whichever of the previous cases, but then, not too much far, the program breaks in a (different) KeyError. -> None is written in the log.

Exception in thread Thread-1: Traceback (most recent call last): File "C:\Users\DS_Pandora\Anaconda2\lib\threading.py", line 801, in bootstrap_inner self.run() File "C:\Users\DS_Pandora\Anaconda2\lib\threading.py", line 754, in run self.target(*self.args, **self.kwargs) File "C:\PCBasic_Brewer_Repo\pcbasic\pcbasic\main.py", line 164, in run_session session.execute(cmd) File "C:\PCBasic_Brewer_Repo\pcbasic\pcbasic\basic\session.py", line 250, in execute self.interpreter.loop() File "C:\PCBasic_Brewer_Repo\pcbasic\pcbasic\basic\interpreter.py", line 107, in loop self.parse() File "C:\PCBasic_Brewer_Repo\pcbasic\pcbasic\basic\interpreter.py", line 96, in parse self.parser.parse_statement(ins) File "C:\PCBasic_Brewer_Repo\pcbasic\pcbasic\basic\parser\statements.py", line 90, in parse_statement self._callbacksc File "C:\PCBasic_BrewerRepo\pcbasic\pcbasic\basic\memory\memory.py", line 379, in let value = next(args) File "C:\PCBasic_Brewer_Repo\pcbasic\pcbasic\basic\parser\statements.py", line 1196, in _parse_let yield self.parse_expression(ins) File "C:\PCBasic_Brewer_Repo\pcbasic\pcbasic\basic\parser\statements.py", line 109, in parse_expression val = self.expression_parser.parse(ins) File "C:\PCBasic_Brewer_Repo\pcbasic\pcbasic\basic\parser\expressions.py", line 318, in parse self._drain(0, operations, units) File "C:\PCBasic_Brewer_Repo\pcbasic\pcbasic\basic\parser\expressions.py", line 335, in _drain units.append(oper(args)) File "C:\PCBasic_Brewer_Repo\pcbasic\pcbasic\basic\values\values.py", line 99, in wrapped_fn return fn(args, **kwargs) File "C:\PCBasic_Brewer_Repo\pcbasic\pcbasic\basic\values\values.py", line 707, in add return left.add(right) File "C:\PCBasic_Brewer_Repo\pcbasic\pcbasic\basic\values\strings.py", line 61, in add return self.new().from_str(self.dereference() + right.dereference()) File "C:\PCBasic_Brewer_Repo\pcbasic\pcbasic\basic\values\strings.py", line 39, in dereference return self._stringspace.view(length, address).tobytes() File "C:\PCBasic_Brewer_Repo\pcbasic\pcbasic\basic\values\strings.py", line 190, in view return memoryview(self._retrieve(length, address)) File "C:\PCBasic_Brewer_Repo\pcbasic\pcbasic\basic\values\strings.py", line 181, in _retrieve return bytearray() if length == 0 else self._strings[address] KeyError: 63343

-Case 5, with -s=256 and --reserved-memory=0 : Got exactly the same as case 4, and it breaks in the same address. -> None is written in the log.

-Case 6, with -s=512 and --reserved-memory=0 : Got exactly the same as case 1, out of memory in line 31003. -> None is written in the log.

Then I have also pulled all your new commits to my pcbasic_brewer version, in order to print out the memory addressing messages, and here are the logs that I obtain repeating these cases with my version, I hope they can help you:

Case1_pcbasic_brewerlog-s128.txt Case2_pcbasic_brewerlog-s256.txt Case3_pcbasic_brewerlog-s512.txt

Case4_pcbasic_brewerlog-s128.txt Case5_pcbasic_brewerlog-s256.txt Case6_pcbasic_brewerlog-s512.txt

I'm a bit lost with these memory issues...

Just to clarify that I'm testing a functional BASIC program, the "out of memory" issues that PCBASIC gives me does not happen in GWBASIC.

For developing/debugging only: why not to create an extra argument like "--memory-addressings=True" in order to make your master branch to write the memory addressings messages in the log files? (As it is in my pcbasic-brewer version log files)

Would you like to meet at any time by skype?, I could help you to set up this program in your pc if you need it, is a good and challenging testing program for sure!

Regards

robhagemans commented 6 years ago

Thanks for the stack traces! A bit disappointing as I was quite convinced I'd nailed the issue by now...

When you're saying the 'out of memory' errors don't happen in GW-BASIC, is it precisely the same string of programs you run with the same inputs? What settings do you use (number of files, size of serial buffer, etc.)? What is the number of free bytes reported at the start screen, both in GW-BASIC and PC-BASIC (60300 with default settings but it will vary with e.g. the number of files)? I'm asking because I'm fairly sure these errors only happen when the memory is actually full; it will always run a garbage collection cycle first to ensure free space is maximised. So if more memory is in use in PC-BASIC than in GW-BASIC, I'm struggling to think of what might cause that. Could you SAVE the program as it is in memory at the time of the error and share it here?

As to extra arguments, I'm a bit hesitant to add more configuration options - it's a frequent request for all sorts of things, there are already well too many of them and even a boolean option theoretically doubles the possible number of code paths to be tested. I also personally find generic logging not that useful... I prefer adding logging ad hoc when I research an issue and removing it afterwards.

I can have a look at setting up your fork if I find some time, I'm squeezing this in in between work and other things. To be honest, it looks Windows-specific and I'm a bit averse to setting up stuff on Windows - I find it very frustrating/hostile as a development platform (in particular for Python!) so I minimise the time I spend on it outside of work. Can the programs you use be run on standard PC-BASIC at all and can they be run without the instrument present?

robhagemans commented 6 years ago

OK, I've identified two issues:

Neither of these explain case(4) though, so could you please still post the .crashlog for that case?

Danitegue commented 6 years ago

Case 3: Ok, perfect.

Case 4: None crashlog is written into C:\Users\DS_Pandora\AppData\Roaming\pcbasic-dev. Running it from cmd and interface=ansi no blue screen is shown at any moment. It simply quits to cmd, and no trace of the error can be seen. Running it from pycharm and interface=sdl2 the interface is closed abruptly when the program breaks and I can see the trace of the error in the console of pycharm, which is what I copied in the last message. What can be the cause of no crashlog being written?

Respect the PCBASIC vs GWBASIC options I'm running the same program, in offline mode (no instrument connected needed), and once the program is loaded, I'm trying to execute the same test routines "PDHP" wich runs the routine "PD" and then "HP". In the launchers always has to be defined two enviroment variables: NOBREW=1 -> This indicate that the program is going to be run without any instrument connected (offline mode). BREWDIR=C:\ -> This indicate where to find the main.asc BASIC program, (respect the mounted units)

Here the options I use to run it on PCBASIC: set brewdir=c:\ set nobrew=1 %PCBASIC_PATH%\ansipipe-launcher.exe %PYTHON_DIR%\python.exe %PCBASIC_PATH%\run.py --mount=C:%MOUNT_C%,D:%MOUNT_D% --interface=ansi --scaling=native --run=%PROGRAM% --quit=False --shell=native -f=10 -s=128 --reserved-memory=0 --double=True --logfile=C:\Temp\pcbasic_log.txt

(I'm trying with different -s options for testing, and with and without --double=True, but I'm having the same results.)

Here the options used to run it on GWBASIC: (PCBasic_Brewer_Repo\brw#185\Program\BREWER.BAT) set brewdir=c:\ set nobrew=1 gwbasic main.asc /f:10

(Only the number of files is set)

Respect the free memory comparison, I have not GWBASIC available just now in my pc, but on Tuesday I will do the comparisons with the PC in which is running the instrument (win98!).

Here the results of the SAVE command after the out of memory, for the cases in which it happens (Case1, 2 and 5): SAVE_CASES.zip

Respect the setup of the program: The limitation is not the program, is GWBASIC which is for win32 bits. We can make the program work on linux or wathever OS if we run it using PCBASIC. No modifications are needed in your original code to make it run. Only the folder brw#185 is needed for having the program in your side. https://github.com/Danitegue/PCBasic_Brewer_Repo/tree/master/brw%23185

Here a copy of the launcher I use to run it on your pcbasic master branch Launcher_brewer185_nobrew.zip

For make it work, it is only needed to download the program folder, and set up the paths in the launcher accordingly.

Danitegue commented 6 years ago

For all cases, I have had always in PCBASIC.INI: debug=True, but no crashlog is written.

robhagemans commented 6 years ago

Thanks for all the info!

To get the crash log and "blue screen", you actually need to switch of debug mode and set debug=False. In debug mode the exception is not caught.

robhagemans commented 6 years ago

Does the out of memory still happen after the latest commits? These should fix the issues with DELETE eating up memory

robhagemans commented 6 years ago

I can sort-of run the program but it breaks on the attempt to read OP_ST.FIL which i apparently shorter than it expects... not sure why:

$ export BREWDIR="c:\\"
$ export NOBREW=1
$ ~/Projects/basic-project/pc-basic/pcbasic.sh --mount=c:.,d:../bdata185 --run=c:main.asc -b --max-files=10 -s=128 -d 

           ***********************************************                      
           *                                             *                      
           *                  MSC/EC/K&Z/IOS             *                      
           *          ALL Brewers Operating Program      *                      
           *         Version 4.10 - Full Release (IOS)   *                      
           *               24/06/2014 01:00:00           *                      
           *                                             *                      
           *     Originally written by  Dr. JB Kerr      *                      
           * Adapted for the IBM PC by  Dr. CT McElroy   *                      
           *       Maintained by Volodya Savastiouk      *                      
           ***********************************************                      
           ** Copyright(C) 1994 SCI-TEC Instruments Inc.**                      
           ***********************************************                      

                      ***  Merging init.rtn  ***                                
                               17:17:47                                         
     Initializing                                                               
Input past end in 5320 
Ok                                                                              
list 5320                                                                       
5320 IF NO$= "-1" THEN OPEN "op_st.fil" FOR INPUT AS 8:INPUT#8,NO$,DD$:CLOSE 8:G
OSUB 5395:GOSUB 2500:CL$=CHR$(12)                                               
Ok                                                                              

EDIT: I know what causes it, it's good old CR/LF versus LF line endings. Git downloads the text file in native format for my machine so I get CHR$(10) line endings where BASIC expects CHR$(13)+CHR$(10)...

robhagemans commented 6 years ago

Cool, after converting some files to DOS line endings I can run it and reproduce the error, which happens in

13120 O1$="M,"+N9$+","+STR$(INT(VAL(MAX$)+.5)):GOSUB 9450

ERROR: Traceback (most recent call last):
  File "/home/rob/Projects/basic-project/pc-basic/pcbasic/basic/session.py", line 384, in _handle_exceptions
    yield
  File "/home/rob/Projects/basic-project/pc-basic/pcbasic/basic/session.py", line 250, in execute
    self.interpreter.loop()
  File "/home/rob/Projects/basic-project/pc-basic/pcbasic/basic/interpreter.py", line 107, in loop
    self.parse()
  File "/home/rob/Projects/basic-project/pc-basic/pcbasic/basic/interpreter.py", line 96, in parse
    self.parser.parse_statement(ins)
  File "/home/rob/Projects/basic-project/pc-basic/pcbasic/basic/parser/statements.py", line 90, in parse_statement
    self._callbacks[c](parse_args(ins))
  File "/home/rob/Projects/basic-project/pc-basic/pcbasic/basic/memory/memory.py", line 386, in let_
    value = next(args)
  File "/home/rob/Projects/basic-project/pc-basic/pcbasic/basic/parser/statements.py", line 1194, in _parse_let
    yield self.parse_expression(ins)
  File "/home/rob/Projects/basic-project/pc-basic/pcbasic/basic/parser/statements.py", line 107, in parse_expression
    val = self.expression_parser.parse_expression(ins)
  File "/home/rob/Projects/basic-project/pc-basic/pcbasic/basic/parser/expressions.py", line 248, in parse_expression
    return self.parse(ins)
  File "/home/rob/Projects/basic-project/pc-basic/pcbasic/basic/parser/expressions.py", line 323, in parse
    self._drain(0, operations, units)
  File "/home/rob/Projects/basic-project/pc-basic/pcbasic/basic/parser/expressions.py", line 340, in _drain
    units.append(oper(*args))
  File "/home/rob/Projects/basic-project/pc-basic/pcbasic/basic/values/values.py", line 99, in wrapped_fn
    return fn(*args, **kwargs)
  File "/home/rob/Projects/basic-project/pc-basic/pcbasic/basic/values/values.py", line 707, in add
    return left.add(right)
  File "/home/rob/Projects/basic-project/pc-basic/pcbasic/basic/values/strings.py", line 61, in add
    return self.new().from_str(self.dereference() + right.dereference())
  File "/home/rob/Projects/basic-project/pc-basic/pcbasic/basic/values/strings.py", line 39, in dereference
    return self._stringspace.view(length, address).tobytes()
  File "/home/rob/Projects/basic-project/pc-basic/pcbasic/basic/values/strings.py", line 190, in view
    return memoryview(self._retrieve(length, address))
  File "/home/rob/Projects/basic-project/pc-basic/pcbasic/basic/values/strings.py", line 181, in _retrieve
    return bytearray() if length == 0 else self._strings[address]
KeyError: 63344

I'll be doing some research...

robhagemans commented 6 years ago

OK, with latest commits I can run this (calling PHDP several times) without crashes or Out of Memory errors.

For reference, I'm calling PC-BASIC as follows, with various values for -s:

$ cd brw#185/Program/
$ export BREWDIR=.
$ export NOBREW=1
$~/Projects/basic-project/pc-basic/pcbasic.sh --mount=c:.,d:../bdata185 --run=c:main.asc --max-files=10 -s=128 -d
Danitegue commented 6 years ago

Perfect!!. I have tested the new improvements it and it works fine!, the problem seems to be solved!. Thanks a lot for your help, it would have been impossible for me to deal with these memory issues.

Now I'm going to continue with the instrument com port communications. I will keep you updated, thanks for all!!

robhagemans commented 6 years ago

Cool!

I'm going to close this issue in that case - it's getting very long and annoying to scroll to the bottom all the time.

If something comes up, please feel free to open a new one. Looking forward to feedback on the serial port handling, as I don't have a serial port...

robhagemans commented 6 years ago

By the way, thanks for your help & persistence with this @Danitegue, we've solved rather a large number of bugs from this one bug report that might otherwise have lingered for quite some time...

Danitegue commented 6 years ago

You're welcome. You program is really a piece of art. I'm gratefull to have collaborated in it. We keep in contact, bye!.