Author Topic: Possible deadlock BASS_Mixer_ChannelGetLevel + BASS_ChannelGetData  (Read 4144 times)

yps

  • Posts: 144
Hi Ian,

one of my users has come across a situation where BASS_Mixer_ChannelGetLevel and BASS_ChannelGetData seem to block each other:

Thread 1 (GUI thread trying to fetch audio levels):

7766f8ca +0000e ntdll.dll                                 NtWaitForSingleObject
77688d23 +16a63 ntdll.dll                                 RtlEnterCriticalSection
10504000 +0004d bassmix.dll                               BASS_Mixer_ChannelGetLevel
...

Thread 2 - actually an ASIOPROC:

thread $100c: <priority:15>
7766f8ca +00e ntdll.dll                                    NtWaitForSingleObject
768714a5 +092 KERNELBASE.dll                               WaitForSingleObjectEx
7663118f +03e kernel32.dll                                 WaitForSingleObjectEx
76631143 +00d kernel32.dll                                 WaitForSingleObject
1101d52e +350 bass.dll                                     BASS_ChannelGetData
00c45d3a +012 xxx.exe   BassASIOPhysicalDevice 100 +7 PlaybackAsioProc
004a9e79 +00d xxx.exe   madExcept                     CallThreadProcSafe
004a9ede +032 xxx.exe   madExcept                     ThreadExceptFrame
76633388 +010 kernel32.dll                                 BaseThreadInitThunk
>> created by main thread ($d34) at:
09cb158e +000 asioqua.dll

File versions:

10500000 bassmix.dll             2.4.7.2           
11000000 bass.dll                2.4.10.0          (mp3-free)

Mixer was created with BASS_STREAM_DECODE, BASS_SAMPLE_FLOAT and BASS_MIXER_NONSTOP.

At the time the freeze occured, there was one source channel plugged into the mixer, which had just finished playing (might be coincidence though). There were no other BASS calls active in any other thread, that's why I think it must be related to these two functions being called at the same time.

Any idea why this might happen?


Thanks,

Torben

Ian @ un4seen

  • Administrator
  • Posts: 20389
The BASS_Mixer_ChannelGetLevel call is waiting for a lock on the channel's mixer. The BASS_ChannelGetData thread call stack appears to be missing some internal function frames, so it isn't possible to tell where exactly it is from that, but it would be holding a lock on the channel at that point. I guess the BASS_ChannelGetData call is on the mixer that the BASS_Mixer_ChannelGetLevel channel is plugged in? If so, that explains what the BASS_Mixer_ChannelGetLevel call is waiting for. If there's a deadlock, then presumably something within the BASS_ChannelGetData call is also waiting for the main thread (which is stuck in BASS_Mixer_ChannelGetLevel). A typical cause of that is a callback function doing something that has to wait for the main thread, eg. UI updating stuff. Do you have any callbacks set on the mixer or its sources, and if so, are any of them doing anything that has to wait for the main thread? If so, you could try making the callback function post a message to the main thread/window and have the message handler do the main thread stuff.

I don't think there were any changes that would influence this, but you could also give this latest BASSmix build a try...

   www.un4seen.com/stuff/bassmix.zip

If the problem persists, would it be possible generate a dump file of it, eg. using Task Manager's "Create Dump File" option? If so, please upload that to have a look at here...

   ftp.un4seen.com/incoming/

yps

  • Posts: 144
Thanks for your quick reply.

As far as I can see, there were not callbacks active. I generally don't handle callbacks directly, but always post a message to the GUI thread, pretty much like you suggested. (The Delphi VCL is not threadsafe, so you cannot make GUI updates from another thread anyway.)

I have uploaded the full bug report and all callstacks to your FTP. It contains some personal information from the user, so I can't post it here. The only BASS related active code I see is the two threads I mentioned above, and some idle threads created by BASS_Init, probably related to playback devices.

I wonder why this occured exactly when the channel finished playing. Perhaps BASS_Mixer_ChannelGetLevel is waiting for more data to arrive, which will never happen? I'm using BASS_MIXER_BUFFER, but not BASS_STREAM_AUTOFREE, when adding the channels.

Regarding the update and dump file, I will point my user at this thread and the instructions you gave.

Ian @ un4seen

  • Administrator
  • Posts: 20389
I wonder why this occured exactly when the channel finished playing. Perhaps BASS_Mixer_ChannelGetLevel is waiting for more data to arrive, which will never happen? I'm using BASS_MIXER_BUFFER, but not BASS_STREAM_AUTOFREE, when adding the channels.

Do you have any syncs triggered when the end is reached? If so, it could be worth checking that stuff.

BASS_Mixer_ChannelGetLevel won't ever wait for data (it will just use whatever is currently available). The provided call stacks show that the BASS_Mixer_ChannelGetLevel call is definitely waiting to acquire a lock on the mixer; it's just the location of the BASS_ChannelGetData thread and what it's waiting for that I can't be sure about. A dump file should reveal that. By the way, please use the latest BASSmix build (posted above) when generating the dump file, to confirm that the problem is still happening with that.

yps

  • Posts: 144
Hi Ian,

the problem has occured again for a couple of times, this time my user was able to generate a dump file which he uploaded straight to your FTP last night.

Code: [Select]
main thread ($d54):
7750f8ca +0000e ntdll.dll                                 NtWaitForSingleObject
77528d23 +16a63 ntdll.dll                                 RtlEnterCriticalSection
10504000 +0004d bassmix.dll                               BASS_Mixer_ChannelGetLevel

Background thread (within WASAPIProc):

Code: [Select]
thread $ed8: <priority:-8>
7750f8ca +00e ntdll.dll                                             NtWaitForSingleObject
760e14a5 +092 KERNELBASE.dll                                        WaitForSingleObjectEx
761d118f +03e kernel32.dll                                          WaitForSingleObjectEx
761d1143 +00d kernel32.dll                                          WaitForSingleObject
1101d52e +350 bass.dll                                              BASS_ChannelGetData

DLL versions:

Code: [Select]
modules:
00230000 bassasio.dll                             1.3.0.0
002e0000 bass_vst.dll                             2.4.0.6
002f0000 bass_wadsp.dll                           2.4.1.0
00310000 basswasapi.dll                           2.4.0.2
10000000 bass_fx.dll                              2.4.9.0
10100000 basswma.dll                              2.4.4.0
10300000 bassenc.dll                              2.4.11.0
10500000 bassmix.dll                              2.4.7.2
11000000 bass.dll                                 2.4.10.0

Hope this information helps to resolve the issue.


Thanks

Torben

Ian @ un4seen

  • Administrator
  • Posts: 20389
It does indeed shed some more light on what's happening. It reveals that the BASS_ChannelGetData call is stuck in a file read request, waiting for more data to be read asynchronously (BASS_ASYNCFILE is enabled). I notice it's also a custom file stream. Is it possible that your FILEREADPROC sometimes stops delivering data before reaching the end? If so, please try upgrading to BASS 2.4.11, as it should handle that better; it will call the FILELENPROC again to check if the length has changed.

yps

  • Posts: 144
Hi Ian,

we have applied the 2.4.11.0 update, but now we're seeing freezes in BASS_StreamCreateFileUser on occasions.

I uploaded another dump file (dump-createfileuser.zip) to your FTP, can you have a look please?


Thanks

Torben

Ian @ un4seen

  • Administrator
  • Posts: 20389
The problem is very similar to last time, if not exactly the same; it is the asynchronous file reading that is stuck. It looks like what happened is that a successful FILESEEKPROC call was followed by a FILEREADPROC that returned 0 (no data). That could indeed result in a deadlock currently. BASS 2.4.11 would avoid the deadlock if the FILELENPROC call (following the FILEREADPROC call) indicated EOF, which it didn't in this case. You could try adding some logging to the FILEREADPROC to find out why it is sometimes returning 0, if you're not expecting it to do so. To avoid it resulting in a deadlock, here is a BASS update that will keep retrying (after a small delay) the FILEREADPROC until it gets some data...

   www.un4seen.com/stuff/bass-mp3free.zip

Let me know if you still get the problem with that.

yps

  • Posts: 144
Ok, that does indeed shed some light on the issue.

The code behind my FILEPROCS does the following: When the file is not on the local disk, but on a network share etc., it starts a thread that creates a copy of the in the local temp dir, just in case the network fails during playback.

Initially all data is retrieved from the original file (so that opening is fast and playback can begin instantly), and when the copy thread has finished, the original file is closed and the temp copy is used instead. This all happens transparently to BASS, as it's hidden in the FILEPROCS.

I suspect the issue arises when the temp copy differs from the original file in some way (although I can't think of a reason why it should be shorter than the original file....).

I have adjusted my code so that it will compare the file sizes at the end of the copy thread, and if they are not the same, it doesn't switch to the temp file but keeps using the original file.

I'll try that with v2.4.11 first, and if it still doesn't work, try your update.

Ian @ un4seen

  • Administrator
  • Posts: 20389
To give a bit more info, the file's current position is at the end of the ID3v2 tags. So it doesn't appear to be a file size issue, unless the switched-in file is smaller than the ID3v2 tags. Are you synchronizing the file switching and the file callback functions, so that both can't happen at the same time? If not, that seems like a potential cause of the problem, ie. perhaps the FILEREADPROC returns 0 while the file is being switched?

yps

  • Posts: 144
Hi Ian,

with BASS 2.4.11.4 (mp3-free), downloaded from the link you gave in your post below, we're now seeing random Access Violation errors.

Code: [Select]
exception class    : EAccessViolation
exception message  : Access violation at address 9DC0FF01. Read of address 9DC0FF01.

thread $1094: <priority:2>
9dc0ff01 +00 ???
004a9e79 +0d xxx.exe madExcept CallThreadProcSafe
004a9ede +32 xxx.exe madExcept ThreadExceptFrame
75eb3368 +10 kernel32.dll           BaseThreadInitThunk
>> created by main thread ($1b7c) at:
64081f9d +00 bass.dll

The error address doesn't really make sense because it is outside the memory range of any loaded module/DLL. madExcept suggests that the error is in a thread that was created by BASS?

Any clue what's going on here? I'm uploading the dump file to your FTP (yps-20150403.zip).

This might or might not be related to the problem described in my original post. I have changed my code so that the file size will be consistent before and after the switch to the temp file (actually the temp file is discarded if the number of bytes copied does not match the size of the original file, for whatever reason), so I don't think this will happen anymore.

However there is only a single (of hundreds) user that was seeing the freeze, and the exact same user is now experiencing these AV errors. So I do suspect the problems to be related.

Ian @ un4seen

  • Administrator
  • Posts: 20389
The uploaded dump file doesn't appear to be from a crash, as it doesn't contain an exception record. There is a thread $1094, but that was in a WaitForSingleObject call at the time the dump was generated. Are you sure it is the correct dump file? If you have any other info in the crash (eg. from the madExcept stuff), please upload that to see if it sheds any light on what happened.

yps

  • Posts: 144
Yes, that thread $1094 appears to be a background thread.

madExcept does catch exceptions in background threads, but then displays an error dialog in the foreground thread. The call stack of $1094 reported by madExcept differs from the one in WinDbg, so I assume the execution of that background thread has continued meanwhile, so we don't see the "error call stack" in the crash dump:

Code: [Select]
  10  Id: 18f8.1094 Suspend: 0 Teb: 7ef86000 Unfrozen
ChildEBP RetAddr 
WARNING: Stack unwind information not available. Following frames may be wrong.
0950f758 75eb1194 ntdll_77490000!ZwWaitForSingleObject+0x15
0950f770 75eb1148 kernel32!WaitForSingleObjectEx+0x43
0950f784 004a0746 kernel32!WaitForSingleObject+0x12
0950f890 004a9f2d xxx!madExcept.HandleException+0x346
0950ff88 75eb336a xxx!madExcept.ThreadExceptFrame+0x81
0950ff94 774c9f72 kernel32!BaseThreadInitThunk+0x12
0950ffd4 774c9f45 ntdll_77490000!RtlInitializeExceptionChain+0x63
0950ffec 00000000 ntdll_77490000!RtlInitializeExceptionChain+0x36

I can try to adjust the madExcept settings so that it halts the thread while the error dialog is displayed.

Anyway, madExcept claims that that thread was created by BASS at 64081f9d, does that code address make any sense?

yps

  • Posts: 144
By the way, do you need the full dump from Task Manager all the time, or will a Mini Dump created with Process Explorer work as well? It's much smaller.

Ian @ un4seen

  • Administrator
  • Posts: 20389
Anyway, madExcept claims that that thread was created by BASS at 64081f9d, does that code address make any sense?

Do you know what BASS.DLL's base address was? BASS.DLL will be loaded at a random address, so the base address is needed to work out where 64081f9d is. From the thread's priority, my guess is that it's the sync thread, so the crash might have occurred in a SYNCPROC callback function. Do you have any debug logging of SYNCPROCs, and if so, does that look fine?

By the way, do you need the full dump from Task Manager all the time, or will a Mini Dump created with Process Explorer work as well? It's much smaller.

A full dump is best, but a mini dump is better than nothing :) ... I think a dump generated by either Task Manager or Process Explorer will only really be useful in deadlock scenarios though, not crashes, as I don't think it'll include an exception record for a crash. For crashes, you can have Windows generate dump files, as described in this post (you may also have to disable madExcept):

   www.un4seen.com/forum/?topic=13959.msg97252#msg97252

yps

  • Posts: 144
Just a quick update. I have added exception handling and logging to all of my SYNCPROCs, but it appears that the exception is not in the SYNCPROC.

From what I can tell from the dumps, the error happens when, or just after, BASS_ChannelSetPosition is called to rewind a channel that has previously been prepared for playback. The dumps are not 100% accurate though, as the threads continue to run for a couple of milliseconds until madExcept stops them.

We have now disabled madExcept and added the localdumps registry patch. Hopefully we'll catch a dump that is more helpful.

yps

  • Posts: 144
Ian, we managed to catch the error in an auto-generated dump file (via your localdumps.reg patch). I'm uploading it to your FTP, file name is yps_dump_150501.zip - can you have a look? Thanks!

yps

  • Posts: 144
On a side node, we have disabled all of my caching code now, but the error still occurs, so it also happens without FILEPROCs. (In the dump I sent you, FILEPROCs are still enabled.)

yps

  • Posts: 144
Here's the output of "analyze -v" in WinDbg, it may save you some time:

Code: [Select]
0:008> !analyze -v
*******************************************************************************
*                                                                             *
*                        Exception Analysis                                   *
*                                                                             *
*******************************************************************************

*** WARNING: Unable to verify checksum for xxx.exe
*** ERROR: Symbol file could not be found.  Defaulted to export symbols for dsp_stereo_tool.dll -
*** ERROR: Symbol file could not be found.  Defaulted to export symbols for bass_wadsp.dll -
*** WARNING: Unable to verify checksum for bassmix.dll
*** ERROR: Symbol file could not be found.  Defaulted to export symbols for bassmix.dll -
*** WARNING: Unable to verify checksum for bassenc.dll
*** ERROR: Symbol file could not be found.  Defaulted to export symbols for bassenc.dll -

FAULTING_IP:
+9534e2000000038
019dc1ff 0000            add     byte ptr [eax],al

EXCEPTION_RECORD:  ffffffff -- (.exr 0xffffffffffffffff)
ExceptionAddress: 019dc1ff
   ExceptionCode: c0000005 (Access violation)
  ExceptionFlags: 00000000
NumberParameters: 2
   Parameter[0]: 00000001
   Parameter[1]: ffffd8f0
Attempt to write to address ffffd8f0

CONTEXT:  00000000 -- (.cxr 0x0;r)
eax=00000000 ebx=07daf710 ecx=00002710 edx=00000000 esi=00000002 edi=00000000
eip=777e015d esp=07daf6c0 ebp=07daf75c iopl=0         nv up ei pl zr na pe nc
cs=0023  ss=002b  ds=002b  es=002b  fs=0053  gs=002b             efl=00000246
ntdll!NtWaitForMultipleObjects+0x15:
777e015d 83c404          add     esp,4

DEFAULT_BUCKET_ID:  INVALID_CLASS_PTR_WRITE

PROCESS_NAME:  xxx.exe

ERROR_CODE: (NTSTATUS) 0xc0000005 - Die Anweisung in 0x%08lx verweist auf Speicher 0x%08lx. Der Vorgang %s konnte nicht im Speicher durchgef hrt werden.

EXCEPTION_CODE: (NTSTATUS) 0xc0000005 - Die Anweisung in 0x%08lx verweist auf Speicher 0x%08lx. Der Vorgang %s konnte nicht im Speicher durchgef hrt werden.

EXCEPTION_PARAMETER1:  00000001

EXCEPTION_PARAMETER2:  ffffd8f0

WRITE_ADDRESS:  ffffd8f0

FOLLOWUP_IP:
bass+1d6c
74a11d6c f7d8            neg     eax

NTGLOBALFLAG:  0

APPLICATION_VERIFIER_FLAGS:  0

APP:  xxx.exe

ANALYSIS_VERSION: 6.3.9600.17298 (debuggers(dbg).141024-1500) x86fre

FAULTING_THREAD:  00001208

PRIMARY_PROBLEM_CLASS:  INVALID_CLASS_PTR_WRITE

BUGCHECK_STR:  APPLICATION_FAULT_INVALID_CLASS_PTR_WRITE_INVALID_POINTER_WRITE

LAST_CONTROL_TRANSFER:  from 74a11d6c to 019dc1ff

STACK_TEXT: 
WARNING: Frame IP not in any known module. Following frames may be wrong.
07dafebc 74a11d6c 07fb4f18 ffffd8f0 1e744890 0x19dc1ff
07dafef0 74a2ef46 80000e8c 00000002 07daff44 bass+0x1d6c
07daff1c 74a2f273 80000e8c 00000002 07daff44 bass!BASS_ChannelSeconds2Bytes+0x65b
07daff88 75c4336a 00000000 07daffd4 777f9f72 bass!BASS_ChannelSetAttribute+0x16
07daff94 777f9f72 00000000 32448479 00000000 kernel32!BaseThreadInitThunk+0xe
07daffd4 777f9f45 74a295d8 00000000 00000000 ntdll!__RtlUserThreadStart+0x70
07daffec 00000000 74a295d8 00000000 00000000 ntdll!_RtlUserThreadStart+0x1b


STACK_COMMAND:  ~8s; .ecxr ; kb

SYMBOL_STACK_INDEX:  1

SYMBOL_NAME:  bass+1d6c

FOLLOWUP_NAME:  MachineOwner

MODULE_NAME: bass

IMAGE_NAME:  bass.dll

DEBUG_FLR_IMAGE_TIMESTAMP:  54e37206

FAILURE_BUCKET_ID:  INVALID_CLASS_PTR_WRITE_c0000005_bass.dll!Unknown

BUCKET_ID:  APPLICATION_FAULT_INVALID_CLASS_PTR_WRITE_INVALID_POINTER_WRITE_bass+1d6c

ANALYSIS_SOURCE:  UM

FAILURE_ID_HASH_STRING:  um:invalid_class_ptr_write_c0000005_bass.dll!unknown

FAILURE_ID_HASH:  {4f034be7-25df-8b69-2c09-88fde11306a3}

Followup: MachineOwner
---------


BASS.DLL is version 2.4.11.4, not sure if MP3-free or not. File size is 102,527 bytes, MD5 is a7956ca53c513d6e554eaf1e6949a4eb

Ian @ un4seen

  • Administrator
  • Posts: 20389
Yep, this crash isn't related to file stuff; it happened in a BASS_ChannelSetAttribute call to set the volume. I'm not 100% certain what caused it, but I have an idea and here's an update for you to try...

   www.un4seen.com/stuff/bass.zip

If you still get the crash with that, please upload the new dump file to have a look at.

yps

  • Posts: 144
Will do, thanks.

yps

  • Posts: 144
The problem has not occured anymore, so I think this can be closed - thank you so much.

yps

  • Posts: 144
Hi Ian, sorry for posting to this very old topic, but we have experienced the same error again as described in the original post, apparent deadlock between BASS_Mixer_ChannelGetLevel and BASS_ChannelGetData (for the mixer), even with recent BASS/BASSmix versions.

70bc0000 bassmix.dll          2.4.8.0 
6d9b0000 bass.dll             2.4.12.1   

I uploaded a full dump file to your FTP, yps-dump-20170718.zip.

Any idea what's going on? It happens only very rarely, sometimes only every other week or so. User says it's when he's playing many short files in a row in the same mixer (with WASAPI output).

Ian @ un4seen

  • Administrator
  • Posts: 20389
Please check if the problem still happens with these latest BASS and BASSmix builds too, and upload a new dump file if so.

   www.un4seen.com/stuff/bass.zip
   www.un4seen.com/stuff/bassmix.zip

yps

  • Posts: 144
Thank's, we'll give it a shot.