Bugzilla – Bug 11896
Repeated error is generated >100 times per second by SqueezeCenter
Last modified: 2009-09-13 23:04:12 UTC
CRITICAL ISSUE: Repeated error is generated >100 times per second by SqueezeCenter (error shown via Microsoft DebugView). http://technet.microsoft.com/en-us/sysinternals/bb896647.aspx Error in quotes: "[10264] Invalid parameter passed to C runtime function.". Value in brackets is the Windows Process ID associated with the process "SQUEEZ~1.EXE". (See attached screenshot. This is reproducible on a clean Windows Vista 32 machine with all hotfixes applied and all user-disableable plugins disabled. The error constantly drills away against the system causing a critical performance impact... affecting performance/timing sensitive subsystem components (most obvious in video rendering): Direct3D video cannot be rendered at a stable frames per second (when rendering/deinterlacing HD movies or playing 3D video games). No errors produced in server.log with logging defaults. My guess is there might be an issue with the scanner. That's the only thing I can think of that drills away constantly at the system.
In DebugView select "Capture" drop down menu, then select "Capture Win32" (CTRL+W) option.
Not sure of what we can do here...
You could start off by trying to reproduce it or asking for the debug log of a suspected component. I'm guessing maybe the wrong team is looking at this. Anyhow, I'm reporting this issue as a reproducible issue; not, an issue for only one machine. (In reply to comment #2) > Not sure of what we can do here...
Reproducing the erros shown in debugview... That will definitely prove there's a problem with the C code. (In reply to comment #3) > You could start off by trying to reproduce it or asking for the debug log of a > suspected component. I'm guessing maybe the wrong team is looking at this. > Anyhow, I'm reporting this issue as a reproducible issue; not, an issue for > only one machine. > > (In reply to comment #2) > > Not sure of what we can do here...
Mr. Avanessian: The Software Localization Team does not handle this type of error. They are the people that Translate SC into other languages. They have nothing to do with this bug. Thank you for taking the time to debug SC, is it possible to have you attach your debug logs to this report? Then we would be able to see the error you are experiencing an possible fix the issue in a more timely manner.
James: Thanks for the prompt reply. My appologies for not realizing the wrong team commented on this bug. You might have missed, "No errors produced in server.log with logging defaults" in the bug description. Could you please tell me which what items to enable under the debug log settings? I have no idea what component could be causing these errors. Whatever it is, it's happening constantly. (In reply to comment #5) > Mr. Avanessian: The Software Localization Team does not handle this type of > error. They are the people that Translate SC into other languages. They have > nothing to do with this bug. > Thank you for taking the time to debug SC, is it possible to have you attach > your debug logs to this report? Then we would be able to see the error you are > experiencing an possible fix the issue in a more timely manner.
OK, loading up the MS Debug tool (DebugView for Windows v4.76) I too see the error as soon as SqueezeCenter starts to load. Stopping SC stops the error log in MS debug tool I see error(s): 760, 3348. There is NO other data provided by the tool, so a developer will have to look into this further using the C++ debugger to figure out how/why this is happening.
Just a few questions: What Virus Scanner do you have installed Do you have iTunes installed (what version if yes) Is your music library located on the same drive SC is installed in or an external location
Symantec Antivirus Corporate version for Vista. I just recently install itunes; although I dont dont use it. My music library is not installed on the same logical drive under: D:\Multimedia Files\Music\Music\. I can try to move my music library to the same drive as SC. I will also disable my antivirus. I'll uninstall itunes too. If there'a anything else you can think of let me know. (In reply to comment #8) > Just a few questions: > What Virus Scanner do you have installed > Do you have iTunes installed (what version if yes) > Is your music library located on the same drive SC is installed in or an > external location
No, I tried with no AV, iTunes so that's not part of the issue. Music library I had was on same drive, so I don't think location should matter.
Michael, I'm passing this to you to review. Since it doesn't cause any usability problems, I'm not worried about it. However I'd like you to review it as part of my due diligence.
Can't reproduce. Tested on XP with 7.4. Is there any impact to your system if this DebugView tool is not running?
There is definitely an impact on the rest of the system; not in SC itself. That's why I put in the bug report in the first place; and, calling it "Critical". I mentioned the most obvious symptom in the bug description: "..affecting performance/timing sensitive subsystem components (most obvious in video rendering): Direct3D video cannot be rendered at a stable frames per second (when rendering/deinterlacing HD movies or playing 3D video games). I dont notice this in application like web browsing, email, internet chat. But, with timing sensitive apps like TV and games (ie, rendering deinterlaced HDTV (from 29.97fps to 60fps LCD native) or 3D video games (locked at 60fps for LCD display). When I disable SC, video timing is very precise. Anyway, IMHO its probably the right thing to do to fix an discovered error in code rather than to sweep it under the rug.. (In reply to comment #12) > Can't reproduce. Tested on XP with 7.4. Is there any impact to your system if > this DebugView tool is not running?
Andy: To answer your last question, yes I notice the symptoms with DebugView disabled. I dont notice the symptom when disabling SC.
Well I'm curious what's causing it, but DebugView is just about the most useless tool I've ever seen.
Any win32 monitoring debug tool should show show the error thats drilling the system. It's just not DebugView. For example, I just tried using a random freeware debug tool "Debug Monitor string" http://www.codeproject.com/KB/dotnet/Debug_Monitor_string.aspx It shows my system getting hammered with the error "Invalid parameter passed to C runtime function" many times a second. http://s67.photobucket.com/albums/h283/mkanet/?action=view¤t=Screenshot-0628.jpg I've heard that the C++ debugger is relatively easy to use... (In reply to comment #15) > Well I'm curious what's causing it, but DebugView is just about the most > useless tool I've ever seen.
"Invalid parameter passed to C runtime function" is a worthless error message without the actual function in question!
I can trivially reproduce this on Vista 64 with SqueezeCenter 7.1 (as in I did nothing, just fired up Dbgview). This may be a generic Perl issue on Vista. I didn't find a lot of hits; but see this thread where the issue is reported and reproduced with a trivial Perl script: http://getpopfile.org/ticket/45 I didn't attach a debugger; but using Process Explorer from SysInternals (another great tool); I can see that SqueezeCenter has two threads. One appears idle; the other one consumes CPU cycles regularly (it looks like per second but that may just be the sample interval of the tool). Likewise the debug messages occur non-stop. Because it's continuous it's impossible to tell exactly what is happening with this kind of tool. But the thread stack is always reported as this. Looks like Perl is doing a select on a socket; something in the stack below must be waking up periodically and generating the error during it's processing. I guess it's probably the network listener thread for squeezecenter. ntoskrnl.exe!ExpInterlockedFlushSList+0x126f ntoskrnl.exe!KeWaitForMultipleObjects+0xcca ntoskrnl.exe!KeWaitForSingleObject+0x2da ntoskrnl.exe!__misaligned_access+0x35 ntoskrnl.exe!MmUnlockPages+0x1160 ntoskrnl.exe!KeWaitForMultipleObjects+0xe61 ntoskrnl.exe!KeWaitForSingleObject+0x2da ntoskrnl.exe!ObOpenObjectByName+0x145d ntoskrnl.exe!NtDeviceIoControlFile+0x56 ntoskrnl.exe!ZwUnloadKeyEx+0x20d3 wow64cpu.dll!TurboDispatchJumpAddressEnd+0x1fe ntdll.dll!NtDeviceIoControlFile+0x15 WS2_32.dll!select+0x9f perl58.dll!win32_select+0x1fb perl58.dll!Perl_stashpv_hvname_match+0x215d perl58.dll!Perl_sortsv+0x3917 perl58.dll!Perl_runops_standard+0xc SQUEEZ~1.EXE+0x2832 SQUEEZ~1.EXE+0x2b0b SQUEEZ~1.EXE+0xab9d kernel32.dll!BaseThreadInitThunk+0xe ntdll.dll!RtlCreateUserProcess+0x8c ntdll.dll!RtlCreateProcessParameters+0x4e Also, the earlier complaints about DbgView are misdirected IMO. The tool just reports the output of the Win32 OutputDebugString call. The problem here is with the library that logs such a vague debug message not with the viewing tool. OTOH perhaps since it's a debug message they keep it lightweight on purpose assuming that people looking at the message will be using debuggers, etc rather than end users. I don't know that my system has observable performance impact from this; but it is interesting that SqueezeCenter (or perl rather) is the ONLY process on my system that's regularly generating this kind of junk. So definitely a black eye - albeight a minor one.
OK, thanks for the research. I'm going to call ours won't fix as well. Note we will be upgrading to ActivePerl 5.10 for the next release, maybe it will be fixed there.
Andy (and all) I have submitted a few bugs in the past. Each time I was successfully able to prove that there's something broken in the SC code (definite bug that's reproducible by developers willing to try). Instead of fixing each bug, the issues were marked as "won't fix" and blatantly ignored the broken code ; or, sometimes been pushed off into a far future target date. It's probably not necessary to mention my perception from an end user's perspective. Jeff is right about it being a black eye; albeit minor ones like this. (In reply to comment #19) > OK, thanks for the research. I'm going to call ours won't fix as well. > > Note we will be upgrading to ActivePerl 5.10 for the next release, maybe it > will be fixed there.
The bug is not with SC code, that is why it's a won't fix. It could be a bug with ActiveState or Microsoft.
Understood. Thanks for explaining. (In reply to comment #21) > The bug is not with SC code, that is why it's a won't fix. It could be a bug > with ActiveState or Microsoft.
For reference here's the stack that is generating the messages. I'll go look for a related ActivePerl bug but thought I'd document the issue here since it's been raised. Yes it's probably a Perl bug; but it's being caused by SC's use of a particular Perl version in a particular way. It would be good to know whether or not the new ActivePerl actually fixes it (versus just forgetting about it). > kernel32.dll!_OutputDebugStringA@4() msvcrt.dll!__invoke_watson() + 0x9a bytes msvcrt.dll!__get_osfhandle() + 0x347bd bytes perl58.dll!280922da() [Frames below may be incorrect and/or missing, no symbols loaded for perl58.dll] perl58.dll!28087479() perl58.dll!28047e45() perl58.dll!2806298d() perl58.dll!2805d564() perl58.dll!2802478e() perl58.dll!28024635() squeezecenter.exe!00402832() ntdll.dll!_RtlAllocateHeap@12() 000002f8() kernel32.dll!@BaseThreadInitThunk@12() + 0xe bytes ntdll.dll!___RtlUserThreadStart@8() + 0x23 bytes ntdll.dll!__RtlUserThreadStart@8() + 0x1b bytes
Thanks Jeff. (In reply to comment #23) > For reference here's the stack that is generating the messages. I'll go look > for a related ActivePerl bug but thought I'd document the issue here since it's > been raised. > > Yes it's probably a Perl bug; but it's being caused by SC's use of a particular > Perl version in a particular way. It would be good to know whether or not the > new ActivePerl actually fixes it (versus just forgetting about it). > > > kernel32.dll!_OutputDebugStringA@4() > msvcrt.dll!__invoke_watson() + 0x9a bytes > msvcrt.dll!__get_osfhandle() + 0x347bd bytes > perl58.dll!280922da() > [Frames below may be incorrect and/or missing, no symbols loaded for > perl58.dll] > perl58.dll!28087479() > perl58.dll!28047e45() > perl58.dll!2806298d() > perl58.dll!2805d564() > perl58.dll!2802478e() > perl58.dll!28024635() > squeezecenter.exe!00402832() > ntdll.dll!_RtlAllocateHeap@12() > 000002f8() > kernel32.dll!@BaseThreadInitThunk@12() + 0xe bytes > ntdll.dll!___RtlUserThreadStart@8() + 0x23 bytes > ntdll.dll!__RtlUserThreadStart@8() + 0x1b bytes
Looks like everybody should begin recommending that SqueezeCenter not be run on Vista due to the massive number of errors and the resulting performance issues.
Yes, I think that end users have a right to know about this this on the download page. (In reply to comment #25) > Looks like everybody should begin recommending that SqueezeCenter not be run on > Vista due to the massive number of errors and the resulting performance issues.
I've dug into this a bit more (it got me curious which is funny since my primary SC install is actually on my DNS323) with a perl debugger and an assembly debugger. It looks like a generic Win32 bug in the base Perl code. It is NOT fixed by moving to ActivePerl 5.10.0.1004 with SC 7.4 code. This issue occurs in *some* (many) cases when Slim::Utils::Select calls IO::Select. Various calls there in turn call the internal Perl select operation (pp_sys.c). On Win32 that delegates to win32_select (win32/win32sck.c). win32_select includes the following code: FD_ZERO(&nrd); FD_ZERO(&nwr); FD_ZERO(&nex); for (i = 0; i < nfds; i++) { fd = TO_SOCKET(i); if (PERL_FD_ISSET(i,rd)) FD_SET((unsigned)fd, &nrd); if (PERL_FD_ISSET(i,wr)) FD_SET((unsigned)fd, &nwr); if (PERL_FD_ISSET(i,ex)) FD_SET((unsigned)fd, &nex); } errno = save_errno; SOCKET_TEST_ERROR(r = select(nfds, prd, pwr, pex, timeout)); save_errno = errno; for (i = 0; i < nfds; i++) { fd = TO_SOCKET(i); if (PERL_FD_ISSET(i,rd) && !FD_ISSET(fd, &nrd)) PERL_FD_CLR(i,rd); if (PERL_FD_ISSET(i,wr) && !FD_ISSET(fd, &nwr)) PERL_FD_CLR(i,wr); if (PERL_FD_ISSET(i,ex) && !FD_ISSET(fd, &nex)) PERL_FD_CLR(i,ex); } TO_SOCKET is defined as __get_osfhandle() which internally is generating the OutputDebugString calls. Based on this info: http://msdn.microsoft.com/en-us/library/ks2530z6.aspx The _get_osfhandle function returns an operating-system file handle if fd (the low-level file descriptor) is in range and is internally marked as free. Otherwise, the invalid parameter handler is invoked, as described in Parameter Validation. If execution is allowed to continue, this function returns INVALID_HANDLE_VALUE (–1) and sets errno to EBADF, indicating an invalid file handle. It appears that this problem is triggered by bad FDs being passed in and triggering the invalid parameter handler which logs the debug messages. I don't really understand this whole flow well, it's converting between FDs and Win32 handles. I think the problem may be the "for (i = 0; i < nfds; i++) {" loops. nfds is set high in pp_sys.c (8 * maxlen). I think a lot of invalid FDs are being passed in by this mechanism. The fix might be to restructure the loop block to check "PERL_FD_ISSET(i,ex)" BEFORE calling "fd = TO_SOCKET(i)". But again, I don't really understand the details of this flow. I'm suspecting that this isn't even a Vista specific problem; but that Vista may just be doing more strict parameter checking and reporting on the underlying __get_osfhandle() calls. Before the calls probably just raised EBADF internally without triggering the observable OutputDebugString. Based on my understanding of the issue; I don't think SC can address this at all (even with workarounds in the SC perl code). I also have to repeat that I can't confirm any performance degradation on my machine due to this issue. I'll figure out how to raise this as a Win32-specific perl bug next.
Bug filed against activestate: http://bugs.activestate.com/show_bug.cgi?id=82995
7.4 noweb-sqlite has a new event loop using EV, although it will still call select. If you guys can try that with 5.10 I'd appreciate it. I'll install a Vista VM some day soon.
*** Bug 12529 has been marked as a duplicate of this bug. ***
Activestate got right on this bug after it was filed. http://bugs.activestate.com/show_bug.cgi?id=82995#c2 "Fix will be in ActivePerl builds 826 and 1005 for 5.8 and 5.10 respectively." Hopefully the uptake of ActivePerl 5.10 will pick up a build with the fix. If not users can run arbitrary versions of ActivePerl with SC but it's a lot more work to get setup. I'm not sure on SC bug practices; but I'd recommend closing this a FIXED (instead of current WONTFIX) if/when SC ships with a fixed version of ActivePerl. I haven't tested a new SC build in quite awhile so I don't know what versions are used right now.
Thanks for the information. We're indeed using perl 5.10.0/1005.