Watch, Follow, &
Connect with Us

For forums, blogs and more please visit our
Developer Tools Community.


Welcome, Guest
Guest Settings
Help

Thread: Strange threading problem


This question is answered.


Permlink Replies: 9 - Last Post: Aug 15, 2017 6:51 PM Last Post By: Ede Csanádi
Ede Csanádi

Posts: 40
Registered: 10/9/06
Strange threading problem  
Click to report abuse...   Click to reply to this thread Reply
  Posted: Aug 3, 2017 4:20 PM
Hi!

Having a strange threading issue that I have no idea why is happening.

I am using Delphi XE2 but building with XE7 I get the same behavior.
It's a VSTi plugin (a .dll) that generates sound wave forms. Normally the code executes in less then 1 ms, but about every 2-3 seconds there is a peak in processing as high as 9-10 ms on Windows 7, and 14-15 ms on Windows 10. The CPU is an i7 4790K with 4+4 cores. If I set the process CPU affinity to only 1 CPU there is no peak.
The code works as: every note played spawns a thread, so pressing 4 keys spawns 4 threads, when audio sample data is needed, the threads are activated and the note's audio sample data is generated in the thread and when all the threads finish they are mixed together in 1 single thread. All this works under 1 ms normally (4 ms is the available time) but for some unknown reason 1 thread seems like is interrupted for 10 ms for an unknown reason (14-15 ms on Windows 10).
The threading code is also built as a BASS add-on .dll and it's demo app. runs with 16 sources without problems in 1-2 ms, and there is no peak, but this demo app. does not call periodically the processing but in one go as fast as possible, the VSTi plugin is queried every 4 ms.

The code that wakes the threads:

            {$IFDEF DEBUG}
            QueryPerformanceFrequency(PerfFreq);
            QueryPerformanceCounter(BeforeTicks);
            {$ENDIF}
 
            //TimeBeginPeriod(1);
 
            //* Allocate buffer
            for i := 0 to BASSThreadedMixer.Sources.Count - 1 do begin
                 SourceChunkBytes := BASS_ChannelSeconds2Bytes(BASSThreadedMixer.Sources[i].Channel, MixerPlayTime);
                 BASSThreadedMixer.Sources[i].BufferSize := SourceChunkBytes;
                 GetMem(BASSThreadedMixer.Sources[i].Buffer, BASSThreadedMixer.Sources[i].BufferSize);
            end;
            //* Wake the threads
            for i := 0 to BASSThreadedMixer.Sources.Count - 1 do begin
                 SetEvent(BASSThreadedMixer.Sources[i].WakeUpEvent);
            end;
            //* Wait handles
            SetLength(WaitHandleArray, BASSThreadedMixer.Sources.Count);
            for i := 0 to BASSThreadedMixer.Sources.Count - 1 do begin
                 WaitHandleArray[i] := BASSThreadedMixer.Sources[i].FinishedEvent;
            end;
            //* Wait for threads to finish work
            WaitForMultipleObjects(Length(WaitHandleArray), @WaitHandleArray[0], True, INFINITE);
 
            //TimeEndPeriod(1);
 
            //* Mix together the sources
            Result := BASS_ChannelGetData(BASSThreadedMixer.MixerChannel, Buffer, RequestLength);
            //* Free buffer
            for i := 0 to BASSThreadedMixer.Sources.Count - 1 do begin
                 BASSThreadedMixer.Sources[i].BufferSize := 0;
                 if Assigned(BASSThreadedMixer.Sources[i].Buffer) then begin
                    FreeMem(BASSThreadedMixer.Sources[i].Buffer);
                    BASSThreadedMixer.Sources[i].Buffer := nil;
                 end;
            end;
 
            {$IFDEF DEBUG}
            QueryPerformanceCounter(AfterTicks);
            TookTime := (AfterTicks - BeforeTicks) / PerfFreq * 1000;
            if TookTime > 1.0 then begin
                LogStrings('E:\BASSTML.txt', 'Threads: ' + FloatToStr(TookTime) + ' ms');
            end;
            {$ENDIF}


The threads:

procedure TBASSThreadedMixerSourceThread.Execute;
    {$IFDEF DEBUG}
var
    BeforeTicks, AfterTicks, PerfFreq: Int64;
    TookTime, TookTime2: Double;
    {$ENDIF}
begin
    while NOT Terminated do begin
        WaitForSingleObject(WakeUpEvent, INFINITE);
        if NOT Terminated then begin
 
            {$IFDEF DEBUG}
            QueryPerformanceFrequency(PerfFreq);
            QueryPerformanceCounter(BeforeTicks);
            {$ENDIF}
 
            //* Do processing here
            GotData := BASS_ChannelGetData(Channel, Buffer, BufferSize);
 
            {$IFDEF DEBUG}
            QueryPerformanceCounter(AfterTicks);
            TookTime2 := (AfterTicks - BeforeTicks) / PerfFreq * 1000;
            if TookTime2 > 1.0 then begin
                LogStrings('E:\BASSTML.txt', 'Thread BASS_ChannelGetData: ' + FloatToStr(TookTime2) + ' ms');
            end;
            {$ENDIF}
 
            BASS_StreamPutData(Self.PushStream, Buffer, GotData);
            SetEvent(FinishedEvent);
 
            {$IFDEF DEBUG}
            QueryPerformanceCounter(AfterTicks);
            TookTime := (AfterTicks - BeforeTicks) / PerfFreq * 1000;
            if TookTime > 1.0 then begin
                LogStrings('E:\BASSTML.txt', 'Thread finished in: ' + FloatToStr(TookTime) + ' ms');
            end;
            {$ENDIF}
 
        end;
   end;
end;


The code that the aboove BASS_ChannelGetData() calls:

procedure OscillatorGenerator(handle: HSTREAM; buffer: Pointer; length: DWORD; Oscillator: TAudioItemOscillator);
var
    Info: BASS_CHANNELINFO;
    Samples: Integer;
    i, k: Integer;
    StartPosition: Double;
    PSample: PSingle;
    SampleValue: Double;//Single;
    SamplesPerCycle: Double;
    OscillatorValuePosition: Double;
    Params: TOscillatorParams;
    OscillatorFreq: Double;
    ProcessedPerc: Double;
    FMBuffer: PSingle;
    FMBufferValue: PSingle;
    {$IFDEF DEBUG}
    BeforeTicks, AfterTicks, PerfFreq: Int64;
    TookTime, TookTime2: Double;
    {$ENDIF}
begin
 
    {$IFDEF DEBUG}
    QueryPerformanceFrequency(PerfFreq);
    QueryPerformanceCounter(BeforeTicks);
    {$ENDIF}
 
    Params := Oscillator.Params^;
    BASS_ChannelGetInfo(handle, Info);
    Samples := length div Info.chans div SizeOf(Single);
    PSample := buffer;
    SamplesPerCycle := Oscillator.freq;
    OscillatorFreq := Oscillator.RateNote;
    StartPosition := Oscillator.Position * (SamplesPerCycle / OscillatorFreq);
    ProcessedPerc := 0;
 
    //* FM
    FMBuffer := nil;
    FMBufferValue := nil;
    if Oscillator.FMSources.Count > 0 then begin
        GetMem(FMBuffer, length);
        //FMBuffer := AllocMem(length);
        //SetLength(FMBuffer, Samples);
        //FMBuffer := VirtualAlloc(nil, length, MEM_COMMIT OR MEM_RESERVE, 0);
        BASS_ChannelGetData(Oscillator.InputFMMixerChannel, FMBuffer, length);
        FMBufferValue := FMBuffer;
    end;
 
    {$IFDEF DEBUG}
    QueryPerformanceCounter(AfterTicks);
    TookTime2 := (AfterTicks - BeforeTicks) / PerfFreq * 1000;
    if TookTime2 > 1.0 then begin
        LogStrings('E:\BASSTML.txt', 'InputFMMixerChannel GetData: ' + FloatToStr(TookTime2) + ' ms'); //* This line nealry never shows up in the log
    end;
    {$ENDIF}
 
    if Info.chans = 1 then begin
        case Oscillator.OscillatorType of
            otSine: begin
                //* Generate sample data here, long but very simple inlined code
            end;
        end;
    end;
 
 
    {$IFDEF DEBUG}
    QueryPerformanceCounter(AfterTicks);
    TookTime2 := (AfterTicks - BeforeTicks) / PerfFreq * 1000;
    if TookTime2 > 1.0 then begin
        case Oscillator.OscillatorType of
            otSine: LogStrings('E:\BASSTML.txt', 'Before finished otSine in: ' + FloatToStr(TookTime2) + ' ms');
            otSaw: LogStrings('E:\BASSTML.txt', 'Before finished otSaw in: ' + FloatToStr(TookTime2) + ' ms');
        end;
    end;
    {$ENDIF}
 
    if Assigned(FMBuffer) then begin
        FreeMem(FMBuffer);
        //VirtualFree(FMBuffer, 0, MEM_RELEASE);
    end;
 
    {$IFDEF DEBUG}
    QueryPerformanceCounter(AfterTicks);
    TookTime := (AfterTicks - BeforeTicks) / PerfFreq * 1000;
    if TookTime > 1.0 then begin
        case Oscillator.OscillatorType of
            otSine: LogStrings('E:\BASSTML.txt', 'Before finished otSine in: ' + FloatToStr(TookTime2) + ' ms');
            otSaw: LogStrings('E:\BASSTML.txt', 'Before finished otSaw in: ' + FloatToStr(TookTime2) + ' ms');
        end;
        case Oscillator.OscillatorType of
            otSine: LogStrings('E:\BASSTML.txt', 'Finished otSine in: ' + FloatToStr(TookTime) + ' ms');
            otSaw: LogStrings('E:\BASSTML.txt', 'Finished otSaw in: ' + FloatToStr(TookTime) + ' ms');
        end;
    end;
    {$ENDIF}
 
end;


The log I get is for example:

Before finished otSaw in: 0.0186879091020101 ms
Finished otSaw in: 10.0781589798347 ms
Thread BASS_ChannelGetData: 10.4683010821835 ms
Thread finished in: 10.5335807646632 ms
Threads: 10.6029564272199 ms
Global finished in: 10.6969079702396 ms
-------------------------------
Thread BASS_ChannelGetData: 9.94043164974046 ms
Threads: 10.1651985564742 ms
Global finished in: 10.2227982763092 ms


As you can see in the log, sometimes the hog happens inside the audio sample data generator code but sometimes after leaving it but still within the BASS_ChannelGetData() call, as in the log the otSaw log does not show up which means it completed below 1 ms.

IsMultiThread is set to True.

Tried TimeBeginPeriod(1) with no effect.

Tried tpTimeCritical with no effect.

Thank you!
Alex Belo

Posts: 626
Registered: 10/8/06
Re: Strange threading problem
Correct
Click to report abuse...   Click to reply to this thread Reply
  Posted: Aug 4, 2017 11:15 PM   in response to: Ede Csanádi in response to: Ede Csanádi
Ede Csanádi wrote:

Having a strange threading issue that I have no idea why is happening.

To identify culprit you can replace code here and there with dummy
loops instead of actual code.

If behaviour will be the same then this is problem on OS level.

Also you can add memory allocations/deallocations into dummy loops
(with reasonable frequency) to see if memory manger is a bottleneck. Or
simply install other MM like last FastMM (v.4.992) or something like

https://sites.google.com/site/aminer68/intel-tbbmalloc-interfaces-for-delphi-and-delphi-xe-versions-and-freepascal

or

https://sites.google.com/site/aminer68/nedmalloc-interfaces-for-delphi-and-delphi-xe-versions-and-freepascal

Good luck.
--
Alex

Ede Csanádi

Posts: 40
Registered: 10/9/06
Re: Strange threading problem  
Click to report abuse...   Click to reply to this thread Reply
  Posted: Aug 5, 2017 6:22 AM   in response to: Alex Belo in response to: Alex Belo
Thank you very much for your reply!

I already tried replacing the Generator code with a loop of 0.1 ms (that's how long it takes when everything is fine) and I still got the delay. Also as you can see in the second log, the Generator code executed in less then 1 ms (so it's not logged at all) but still the BASS_ChannelGetData() call (that calls the Generator code) executed in 10 ms.

I also tried using WinAPI VirtualAlloc() and VirtualFree() with no difference as you can see in the code.

Ok, I try a different memory manager as you suggested.
Ede Csanádi

Posts: 40
Registered: 10/9/06
Re: Strange threading problem  
Click to report abuse...   Click to reply to this thread Reply
  Posted: Aug 5, 2017 10:21 AM   in response to: Alex Belo in response to: Alex Belo
I tried both memory managers and it seems they both fix the issue. No more logs. But after the note is released the CPU usage display stays as it was while playing (20%) and I can't play any more notes and when I close the host app. it is frozen.
It seems like this would solve the issue but introduces a new one.

EDIT: Tried FastMM4 and it seems it fixes the issue. I just tested it a little will report if it succeeds.

Edited by: Ede Csanádi on Aug 5, 2017 7:30 PM
Alex Belo

Posts: 626
Registered: 10/8/06
Re: Strange threading problem [Edit]
Helpful
Click to report abuse...   Click to reply to this thread Reply
  Posted: Aug 5, 2017 9:36 PM   in response to: Ede Csanádi in response to: Ede Csanádi
Ede Csanádi wrote:

Tried FastMM4 and it seems it fixes the issue.

FastMM locks other threads memory allocations while one of threads
allocates memory (for dynamic object instance for example). Last FastMM
version (4.992) has special mechanics to reduce conficts (or more
precisely to reduce time of conflict resolution). Try special FastMM
configuration keys (see FastMM4Options.inc)

Also you can try pre-allocate needed objects (create a pool of objects)
as much as possible and use them later in threads.

--
Alex
Ede Csanádi

Posts: 40
Registered: 10/9/06
Re: Strange threading problem [Edit]  
Click to report abuse...   Click to reply to this thread Reply
  Posted: Aug 6, 2017 4:44 AM   in response to: Alex Belo in response to: Alex Belo
So it seems under Windows 7 now all is completely fine.

Under Windows 10 now there were much more spikes, adjusted the compiler options, activated all for thread concurrency and now it's much better, thank you very much for pointing me to these directives.

So now under Windows 10 these are the spike values:

Threads: 4,19354136773295 ms
Global finished in: 8,17997847037244 ms
-------------------------------
Threads: 3,20589210354189 ms
Global finished in: 6,76864866387029 ms
-------------------------------
Threads: 3,43910840205875 ms
Global finished in: 6,85287277167715 ms
-------------------------------
Threads: 2,96038778929637 ms
Global finished in: 6,61735247021116 ms


It's nearly 2x as fast as was with the default Delphi memory manager.

Thank you very much for your help I accept now as it is.

I think about it if the less allocation/free can be improved, thank you!
Alex Belo

Posts: 626
Registered: 10/8/06
Re: Strange threading problem [Edit]  
Click to report abuse...   Click to reply to this thread Reply
  Posted: Aug 6, 2017 8:44 AM   in response to: Ede Csanádi in response to: Ede Csanádi
Ede Csanádi wrote:

So it seems under Windows 7 now all is completely fine.

Under Windows 10 now there were much more spikes, adjusted the
compiler options, activated all for thread concurrency and now it's
much better

OK, good to know.

You also can try investigating other memory managers. Many of modern
MMs install local MM in every thread; as a result there are no
conflicts between threads at all. But this strategy has its own
drawbacks: installation/deinstallation of local MM takes some time,
every thread usually uses more memory (to be ready for massive
allocations) and passing pointers between threads also not so easy and
requires additional time for internal processing in MM.

--
Alex
Ede Csanádi

Posts: 40
Registered: 10/9/06
Re: Strange threading problem [Edit]  
Click to report abuse...   Click to reply to this thread Reply
  Posted: Aug 7, 2017 3:05 PM   in response to: Alex Belo in response to: Alex Belo
Ok. Could you please point me to some of these memory managers? It sounds that that would be what I need, mm especially optimized for threads. But it's ok now, the speed is acceptable, I don't want to slow down the single threaded performance though.

BTW. A little looked into FastMM4's code and what came to my mind is: instead of the very slow Sleep(), would using events boost the threaded alloc/free?
I mean I made a test recently for Windows' event functionality and it seemed amazingly fast, maybe 50-60 microseconds for waking a thread. Would it work or a bad idea?
Alex Belo

Posts: 626
Registered: 10/8/06
Re: Strange threading problem [Edit]  
Click to report abuse...   Click to reply to this thread Reply
  Posted: Aug 8, 2017 9:46 AM   in response to: Ede Csanádi in response to: Ede Csanádi
Ede Csanádi wrote:

Could you please point me to some of these memory managers?

Aminer bombs 3-d party newsgroup with many MMs; you tried a couple of
them without success (I don't know why).

Googling returns some MMs and reviews:

New Open Source Multi-Thread ready Memory Manager: SAPMM
(2013, December 5, quite outdated)
http://blog.synopse.info/post/2013/12/05/New-Open-Source-Multi-Thread-ready-Memory-Manager%3A-SAPMM

Delphi Parallel Programming Library & Memory Managers
(February 9, 2016)
http://www.stevemaughan.com/delphi/delphi-parallel-programming-library-memory-managers/

Need multi-threading memory manager
https://stackoverflow.com/questions/6072269/need-multi-threading-memory-manager

BrainMM
https://github.com/d-mozulyov/BrainMM/blob/master/README.md

sapmm (32 bit only)
https://github.com/alan008/sapmm/blob/master/README.md

scalemm
https://github.com/andremussche/scalemm

But it's ok now, the speed is acceptable

So "Don't repair what is not broken.". :-)

instead of the very slow Sleep(), would using events boost the
threaded alloc/free?

I have no idea. I think you can contact with author on githab.

BTW, I still use default FastMM version in CB2007. Probably it's time
to try something newer but replacing of MM in CBuilder is tricky (see
FastMM support for CB and you'll find out what the matter is :-)).

--
Alex
Ede Csanádi

Posts: 40
Registered: 10/9/06
Re: Strange threading problem [Edit]  
Click to report abuse...   Click to reply to this thread Reply
  Posted: Aug 15, 2017 6:51 PM   in response to: Alex Belo in response to: Alex Belo
Wow what a list! Thank you very much for listing all of them! I'll take a look at them, right now I have more important tasks.

The first 2 you recommended previously simply freeze the application. Not much I can test there.

Thank you very much for all your help, really appreciate it!
Legend
Helpful Answer (5 pts)
Correct Answer (10 pts)

Server Response from: ETNAJIVE02