Announcement

Collapse
No announcement yet.

Appending to a file.

Collapse
X
 
  • Filter
  • Time
  • Show
Clear All
new posts

  • Appending to a file.

    With an older application I made, I have some problems I can't really explain. It's a Voice response system for ISDN (T1/E1), which works fine, except for one thing.
    When the system is very busy, it get's slow. (You can see by the delayed updating of the GUI on the screen, and the delayed voicetexts)
    I think it is caused by the logfile the program keeps. Interesting events are logged in a logfile. If very busy, this could be 10 or 20 events a second.
    The logfile is opened (for append) and closed on every event. This to make it easy to copy / delete the logfile periodically.

    I thought that Windows 'shadows' the file in memory, and writes it to disk after a time-out. So I didn't think a lot of opening and closing would have any impact on the PC...

    Can this indeed have a lot of impact, and is there a way to avoid / minimize this?

    (Using PbWin 8.04 / W2KSP4)
    Regards,
    Peter

  • #2
    Just a tought but... maybe an antivirus is finding that file interesting and loose a lot of time checking it?

    Bye!
    -- The universe tends toward maximum irony. Don't push it.

    File Extension Seeker - Metasearch engine for file extensions / file types
    Online TrID file identifier | TrIDLib - Identify thousands of file formats

    Comment


    • #3
      Farm out the write to a queue. Search 'queue' in source code forum. I think you'll find the version using the anonymous pipe pretty much exactly what you are looking for.
      Michael Mattias
      Tal Systems (retired)
      Port Washington WI USA
      [email protected]
      http://www.talsystems.com

      Comment


      • #4
        Curious if you found the slow-down (anti-virus checking?)
        The log file could be in another thread or lock/flush/unlock
        could be used and other processes could read it.
        How long is an idea?

        Comment


        • #5
          >Can this indeed have a lot of impact, and is there a way to avoid / minimize this?

          Yes and not really.

          About all you can do is arrange for the "slow" activity to occur somewhere it does not affect your GUI... eg in another thread of execution running at a lower priority.

          (as shown in the queue demo to which I pointed you).

          Or, I guess you could just launch a thread to execute ...
          Code:
          THREAD FUNCTION AppendtoLogFile (BYVAL pS AS STRING PTR ) AS LONG 
          
            SetThreadPriority GetCurrentThread(), %THREAD PRIORITY_LOWEST 
            szFile = $LOG_FILE_NAME 
            hFile = FREFILE
            OPEN .....
            PRINT #hFile, @PS 
            CLOSE hFile
           
          END FUNCTION 
          
          ....
              LOCAL LogText AS STRING                     ' see SCOPE NOTE BELOW 
              LogText = "Really interesting stuff here"  
             THREAD CREATE AppendToLogFile (BYVAL VARPTR (logText)) TO hThread 
             THREAD CLOSE hThread TO hThread 
          .....
          SCOPE NOTE: If your calling function is going to terminate, you'll have to make logtext STATIC or GLOBAL lest it go out of scope by the time it's called upon to write to the disk file. That or add a ready event and suspend the calling thread until you have copied the data to a variable LOCAL to the thread function and then signalled that event. (Most of my demos of multi-threaded stuff include this event code).


          MCM
          Last edited by Michael Mattias; 17 Apr 2009, 01:57 PM.
          Michael Mattias
          Tal Systems (retired)
          Port Washington WI USA
          [email protected]
          http://www.talsystems.com

          Comment


          • #6
            Curious if you found the slow-down (anti-virus checking?)
            No, tested on a bare machine with same result. I have an option to enable/disable logging, and when disabled, program runs fine...
            But I'll give Michaels suggestion a try.
            I just found it curious that a lot of open/closes of a file had such an impact on the operation of the system...
            Regards,
            Peter

            Comment


            • #7
              Peter, you also might try writing a little less frequently to the disk, while writing to a string in the meantime:
              Code:
              #COMPILE EXE
              #DIM ALL
              %WRITEiNTERVAL = 15 'write to disk ~ every 15 sec.
              
              FUNCTION PBMAIN () AS LONG
                 LOCAL eventString, interestEvent AS STRING, startPos AS QUAD, ii AS LONG
                 
                 eventString = SPACE$(1000000)
                 startPos = 1
                 
                 FOR ii = 1 TO 4000
                    interestEvent = FORMAT$(ii) & "th Interesting event to be logged, and now, without slowing system." & $CRLF
                    MID$(eventString, startPos) = interestEvent
                    startPos += LEN(interestEvent)  'aka. startPos = startPos + LEN(intrestEvent)
                    SLEEP 50                        '20 per second
                    IF ii MOD 40 = 39 THEN          'check every 2 seconds to see if write interval is reached
                       IF logEvents(eventString) = 1 THEN
                          startPos = 1
                          eventString = SPACE$(1000000)
                       END IF
                    END IF
                 NEXT
                 ? "3,999 events have been logged hopefully unnoticed by system"
              END FUNCTION
              
              FUNCTION logEvents(eventString AS STRING) AS LONG
                 STATIC t AS SINGLE
                 IF t = 0 THEN t = TIMER
                 
                  IF TIMER - t >= %WRITEiNTERVAL THEN 'write to disk at selected second interval
                     DO
                        TRY                           'let program wait if you're, say, viewing the file
                           OPEN "c:\interestingEvent.log" FOR APPEND AS #1
                           EXIT DO
                        CATCH
                           SLEEP 200
                        END TRY
                     LOOP
                     PRINT #1, RTRIM$(eventString);
                     CLOSE #1
                     FUNCTION = 1
                     t = TIMER
                  END IF
              END FUNCTION
              Last edited by John Gleason; 17 Apr 2009, 08:11 PM. Reason: formatting

              Comment


              • #8
                You might try setting up a Ram Disk. Peter. That should eliminate lost time. From your description, the slowing down is not a constant (slows some times more than others, indicating the OS is the cuplrit flushing the cache or something, requiring seek time for the drive head) and a Ram Disk would get around that.

                Just a thought.

                ====================================================
                "From the moment I picked your book up
                until I laid it down I was convulsed with laughter.
                Some day I intend reading it."
                Groucho Marx (1895-1977)
                ====================================================
                It's a pretty day. I hope you enjoy it.

                Gösta

                JWAM: (Quit Smoking): http://www.SwedesDock.com/smoking
                LDN - A Miracle Drug: http://www.SwedesDock.com/LDN/

                Comment


                • #9
                  Open/Close to fast?

                  Windows as a Write cache which is usually enabled. Disabling it makes the computer really slow.

                  Is it possible Windows has not finished flushing the write cache/closing the file before your application is requesting to have the file open again?

                  You could try running SysInternals DiskMon and see if it indicates any delays/timeouts/errors/etc... Not sure if it will, but worth a shot.

                  Comment


                  • #10
                    Write after so many events or whenever you want

                    Code:
                    #COMPILE EXE
                    #DIM ALL
                     
                    FUNCTION PBMAIN () AS LONG
                      LOCAL EventCounter AS LONG
                      KILL "\LOG.TXT"            'get rid of previous log
                     
                      FOR EventCounter = 1 TO 1073
                        UpdateLog "Event"+ STR$(EventCounter) + " time " + TIME$
                        IF EventCounter MOD 20 = 0 THEN UpdateLog ""     'flush whenever you want
                      NEXT
                     
                      UpdateLog ""  'flush events still in StaticString
                      SHELL "NOTEPAD \LOG.TXT"   'view results
                    END FUNCTION
                     
                    SUB UpdateLog(sText AS STRING)
                     
                      STATIC StaticString  AS STRING
                      LOCAL hLog           AS LONG
                     
                      IF LEN(sText)THEN
                        StaticString = StaticString + sText + $CRLF
                      ELSE
                        hLog = FREEFILE  'added this line 4/18/09 4:31 AM CST
                        OPEN "\LOG.TXT" FOR APPEND AS hLOG
                        PRINT #hLog, LEFT$(StaticString,LEN(StaticString)-2) 'dont need extra $CRLF after each close
                        CLOSE #hLog
                        StaticString = ""
                      END IF
                    END SUB
                    Last edited by Mike Doty; 18 Apr 2009, 05:31 AM. Reason: Added hLog = FREEFILE
                    How long is an idea?

                    Comment


                    • #11
                      Added hLog = FREEFILE

                      Code:
                      SUB UpdateLog(sText AS STRING)
                       
                        STATIC StaticString  AS STRING
                        LOCAL hLog           AS LONG
                       
                        IF LEN(sText)THEN
                          StaticString = StaticString + sText + $CRLF
                        ELSE
                          hLog = FREEFILE  'added this line 4/18/09 4:31 AM CST
                          OPEN "\LOG.TXT" FOR APPEND AS hLOG
                          PRINT #hLog, LEFT$(StaticString,LEN(StaticString)-2) 'dont need extra $CRLF after each close
                          CLOSE #hLog
                          StaticString = ""
                        END IF
                      END SUB
                      How long is an idea?

                      Comment


                      • #12
                        >Windows as a Write cache which is usually enabled.
                        This does not help during the close, this will flush the data to disk before it returns from close.
                        hellobasic

                        Comment


                        • #13
                          Peter, you also might try writing a little less frequently to the disk, while writing to a string in the meantime..
                          Risks losing log information if 'something bad' happens to program.

                          Worst of all, what will be missing are the events immediately preceding that something bad - more than likely the exact information required to isolate the problem.

                          Not that this cannot occur when you farm out the log writes to another thread of execution, because it can. But IMO using OPEN/WRITE/CLOSE either within the context of the primary TOE or in a worker TOE offers the best chance of preserving all the log information.
                          Michael Mattias
                          Tal Systems (retired)
                          Port Washington WI USA
                          [email protected]
                          http://www.talsystems.com

                          Comment


                          • #14
                            Then again, perhaps instead of farming out the writes to an additional TOE of the primary executable, you could use a separate server EXE to handle it. That way anything which has been sent to the server for "write to the log" purposes would be unaffected by 'something bad' happening in the client program.

                            A lot more work to implement, but depending on the application it may be the very best way to support log writing.
                            Michael Mattias
                            Tal Systems (retired)
                            Port Washington WI USA
                            [email protected]
                            http://www.talsystems.com

                            Comment


                            • #15
                              Writing less frequently code is posted above.
                              How long is an idea?

                              Comment


                              • #16
                                Here is another

                                Code:
                                $LogFile = "\LOG.TXT"
                                FUNCTION PBMAIN () AS LONG
                                  FOR EventCounter& = 1 TO 1073
                                    sBuffer$ = sBuffer$ + "Event"+ STR$(EventCounter&) + " time " + TIME$ + $CRLF
                                    IF EventCounter& MOD 100 = 0 THEN FlushBuffer(sBuffer$):sBuffer$ = ""
                                  NEXT
                                  FlushBuffer(sBuffer$):sBuffer$ = ""
                                  SHELL "NOTEPAD " + $LogFile
                                END FUNCTION
                                SUB FlushBuffer(sBuffer AS STRING)
                                  hLog& = FREEFILE
                                  OPEN $LogFile FOR APPEND AS hLog&
                                  PRINT #hLog&, LEFT$(sBuffer$,LEN(sBuffer$)-2)
                                  CLOSE #hLog&
                                END SUB
                                Last edited by Mike Doty; 18 Apr 2009, 11:47 AM.
                                How long is an idea?

                                Comment

                                Working...
                                X