Message boards :
Number crunching :
Stderr Truncations
Message board moderation
Previous · 1 · 2 · 3 · 4 · 5 · 6 · 7 · 8 . . . 11 · Next
Author | Message |
---|---|
Jeff Buck Send message Joined: 11 Feb 00 Posts: 1441 Credit: 148,764,870 RAC: 0 |
I was just reading Keith's thread about this issue over on MW and noticed that, although Keith has only experienced the completely empty Stderrs, there was another poster back in May, who experienced partial truncation on one machine but complete truncation on another, exactly the same sort of thing I've seen here on S@h. That would seem to make the behavior on both projects appear somewhat similar after all. I had thought it might be OS-dependent, but it looks like both of his machines were running Win 7 (unless he's upgraded one or both since he posted). Perhaps it's more a hardware thing, then, than an OS thing, that factors into the equation. |
jason_gee Send message Joined: 24 Nov 06 Posts: 7489 Credit: 91,093,184 RAC: 0 |
Perhaps it's more a hardware thing, then, than an OS thing, that factors into the equation. Yes. Aside from the OS scheduling the threads, the timing conditions one way or another will be setup and depend on the hardware, drivers (user mode parts and kernel parts), the position(s) on disk where the file(s) are located, the sizes being written, speed and latencies of the memory, what happens to be paged into memory and what not (the list goes on) Proper synchronisation when multiple processes and/or threads are involved removes uncertainty, similar to a queue of many people trying to enter a building. Our systems and underlying layers 'grew' more entry paths for the people (sometime from ~2003 on), but the Boinc code still thinks there is only one orderly queue despite not having added ropelines and burly doormen. [Edit:] Consider the confusion if these three things start close together - Large stderr being written to disk - creating a boinc finished file - terminating the process Reading the list top to bottom looks just fine, until you realise that without synchronisation all 3 can happen starting at the same time on multiple threads (which they do, depending on the size of stderr, and where the finished file needs to go, the termination will be faster, and kill all or part of the other actions). Fortunately the finish file is created a fair bit earlier, but still a chance that can go awol too. it needs to be explicit like: - Large stderr being written to disk ---> commit to disk (blocking synchronisation) - creating a boinc finished file - terminating the process (Asynchronous) ---> Wait for the termination to complete ( spin-wait synchronisation lock enabling cleanup, & that finish file is created [wait yielded to IO completion deferred procedure call]) "Living by the wisdom of computer science doesn't sound so bad after all. And unlike most advice, it's backed up by proofs." -- Algorithms to live by: The computer science of human decisions. |
Jeff Buck Send message Joined: 11 Feb 00 Posts: 1441 Credit: 148,764,870 RAC: 0 |
Perhaps it's more a hardware thing, then, than an OS thing, that factors into the equation. And I suppose with the evaporation of BOINC funding, there's not likely to be any new purchases of rope or hiring of doormen (burly or otherwise) any time soon. [Edit:] Consider the confusion if these three things start close together That all seems simple and sensible to me, except perhaps the part about the "finished file". That strikes me as a rather odd way to raise a signal flag, and seems to have been the root of some other issues that have come up here, as well. I don't think I've understood the rationale for that approach on the other occasions when it's been discussed here, either. But maybe that's just me. ;^) |
Juha Send message Joined: 7 Mar 04 Posts: 388 Credit: 1,857,738 RAC: 0 |
Perhaps in addition to looking at BOINC logs you should use Process Monitor to get a more complete view of the events. |
jason_gee Send message Joined: 24 Nov 06 Posts: 7489 Credit: 91,093,184 RAC: 0 |
I don't think I've understood the rationale for that approach on the other occasions when it's been discussed here, either. But maybe that's just me. ;^) Probably an attempt to stay fairly generic, which would have made sense in posix single thread days. There're separate Windows and other codepaths there, so that logic doesn't completely hold water there either, and whatever you use if multithreaded IO is going on it'll need some synchronisation which varies. Over the years I just figured whoever wrote the code didn't understand non-blocking IO (which fits with other issues in the codebase) One missing/incomplete thing the synchronisation doesn't go into, is the blank stderr after we know we had one with content. That can be several causes, the most likely being that the stderr there is written as a Boinc mfile or MIOfile (memory mapped file) so is cleared on open before the whole thing is written (not the only possibility, but either way a full commit should address that problem) [Edit:] another being the other files such as AP's state ones, and where to keep a list for commit/cleanup, given the api end is generic so doesn't look after those. I would hope the block after the terminateprocess would let the IO complete without further concerns, but then a hard commit before the app calls boinc_finish() shouldn't be a big deal where they are project appliocation managed files. "Living by the wisdom of computer science doesn't sound so bad after all. And unlike most advice, it's backed up by proofs." -- Algorithms to live by: The computer science of human decisions. |
jason_gee Send message Joined: 24 Nov 06 Posts: 7489 Credit: 91,093,184 RAC: 0 |
Perhaps in addition to looking at BOINC logs you should use Process Monitor to get a more complete view of the events. Could show something extra. It was either that or another tool I saw used recently on the dev lists, probably process monitor or similar with log filtering (not sure now). My only concerns with that, which may or may not be an issue, I truly don't know, are similar to what happened with enabling the Boinc logging flags, in that although the problem happened eventually, it appeared to change the frequency. So unwanted effects from the tools would be something to watch out for. "Living by the wisdom of computer science doesn't sound so bad after all. And unlike most advice, it's backed up by proofs." -- Algorithms to live by: The computer science of human decisions. |
Jeff Buck Send message Joined: 11 Feb 00 Posts: 1441 Credit: 148,764,870 RAC: 0 |
Perhaps in addition to looking at BOINC logs you should use Process Monitor to get a more complete view of the events. Can't get away from that cat, huh? ;^) Anyway, I'm certainly game to try it on my two big boxes, though probably not on my daily driver. Any idea what the overhead cost might be? |
Richard Haselgrove Send message Joined: 4 Jul 99 Posts: 14677 Credit: 200,643,578 RAC: 874 |
One missing/incomplete thing the synchronisation doesn't go into, is the blank stderr after we know we had one with content. That can be several causes, the most likely being that the stderr there is written as a Boinc mfile or MIOfile (memory mapped file) so is cleared on open before the whole thing is written (not the only possibility, but either way a full commit should address that problem) How are we defining *blank* in that case? Is it simply seeing an empty space on a website? Are we considering enough of the steps from volunteer's hard disk to project website? What are our evidence gathering tools? |
jason_gee Send message Joined: 24 Nov 06 Posts: 7489 Credit: 91,093,184 RAC: 0 |
Any idea what the overhead cost might be?In the case of Process explorer, very low. Not sure about the process monitor one (If that's even what it was). Funnily enough, I never broke my own threading model, so would have to think about what to even look for, for a while tomorrow. Looking for things happening out of sequence seems a bit moot, give we see periodic bouts of exits with no finished files, truncated/empty stderr and other weirdness on different hosts/situations from time to time. They all point to missing synchronisation (and possibly impatient client too), but simillary just say 'It's broken, do it properly', lol "Living by the wisdom of computer science doesn't sound so bad after all. And unlike most advice, it's backed up by proofs." -- Algorithms to live by: The computer science of human decisions. |
Jeff Buck Send message Joined: 11 Feb 00 Posts: 1441 Credit: 148,764,870 RAC: 0 |
Any idea what the overhead cost might be?In the case of Process explorer, very low. Not sure about the process monitor one (If that's even what it was). Funnily enough, I never broke my own threading model, so would have to think about what to even look for, for a while tomorrow. Looking for things happening out of sequence seems a bit moot, give we see periodic bouts of exits with no finished files, truncated/empty stderr and other weirdness on different hosts/situations from time to time. They all point to missing synchronisation (and possibly impatient client too), but simillary just say 'It's broken, do it properly', lol Process Monitor looks interesting. I just started to read the help file. Process Monitor is an advanced monitoring tool for Windows that shows real-time file system, Registry and process/thread activity. It combines the features of two legacy Sysinternals utilities, Filemon and Regmon, and adds an extensive list of enhancements including rich and non-destructive filtering, comprehensive event properties such session IDs and user names, reliable process information, full thread stacks with integrated symbol support for each operation, simultaneous logging to a file, and much more. Its uniquely powerful features will make Process Monitor a core utility in your system troubleshooting and malware hunting toolkit. |
jason_gee Send message Joined: 24 Nov 06 Posts: 7489 Credit: 91,093,184 RAC: 0 |
One missing/incomplete thing the synchronisation doesn't go into, is the blank stderr after we know we had one with content. That can be several causes, the most likely being that the stderr there is written as a Boinc mfile or MIOfile (memory mapped file) so is cleared on open before the whole thing is written (not the only possibility, but either way a full commit should address that problem) For the API portion of the exercise, truncated to 0 bytes (being the same as other truncations just sooner). Despite other points in the chain can possibly do similar, We know this is some fair proportion of the occurrences, because commit mode builds change [reduce] the frequency. So a reasonable approach might involve comparing the 0 length stderr timestamp (before file deletion/ slot cleanout), to the Boinc logs as to when it did its read. Reading after it's zeroed, and it never appeared in the report confirms one race result as the app termination event cancelling IO. Catching a filled stderr file with timestamp after Boinc's read would indicate a complete write , but Boinc reading too early (which I find difficult to visualise, but then I gather they've been fiddling in that client code, so why not look) "Living by the wisdom of computer science doesn't sound so bad after all. And unlike most advice, it's backed up by proofs." -- Algorithms to live by: The computer science of human decisions. |
jason_gee Send message Joined: 24 Nov 06 Posts: 7489 Credit: 91,093,184 RAC: 0 |
Yep, looks handy, could take some practice :) "Living by the wisdom of computer science doesn't sound so bad after all. And unlike most advice, it's backed up by proofs." -- Algorithms to live by: The computer science of human decisions. |
Richard Haselgrove Send message Joined: 4 Jul 99 Posts: 14677 Credit: 200,643,578 RAC: 874 |
One missing/incomplete thing the synchronisation doesn't go into, is the blank stderr after we know we had one with content. That can be several causes, the most likely being that the stderr there is written as a Boinc mfile or MIOfile (memory mapped file) so is cleared on open before the whole thing is written (not the only possibility, but either way a full commit should address that problem) I certainly caught one filled stderr.txt from Milkyway, under circumstances where I was alerted by a logged error, rushed to the slot directory, and found a single stderr.txt file there, nothing else. I didn't have to to see the timestamp, just opened it in notepad (Milkyway will re-use a slot directory within 60 seconds), but everything was there. I think I even posted about it here (yes, message 1700686, this thread). So, "zero length stderr" isn't a concept I recognise in this conversation, and I haven't seen anyone post evidence about one here. Not a zero-length file on a local disk filing system, that is: plenty of white space on project websites. |
Jeff Buck Send message Joined: 11 Feb 00 Posts: 1441 Credit: 148,764,870 RAC: 0 |
Yep, looks handy, could take some practice :) Holy Cr*p! I figured I'd try Process Monitor on one of my boxes tonight, but just to see what it looked like, I started it up on my daily driver. In less than five minutes it captured over 900K "events". Zeroing in on the Slot folders, here's just a sampling of the display. 3:40:40.2075851 PM boinc.exe 4004 QueryDirectory C:\ProgramData\BOINC\slots\0 NO MORE FILES 3:40:40.2076000 PM boinc.exe 4004 CloseFile C:\ProgramData\BOINC\slots\0 SUCCESS 3:40:42.2362353 PM boinc.exe 4004 CreateFile C:\ProgramData\BOINC\slots\0 SUCCESS Desired Access: Read Data/List Directory, Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened 3:40:42.2363608 PM boinc.exe 4004 QueryDirectory C:\ProgramData\BOINC\slots\0\boinc_finish_called NO SUCH FILE Filter: boinc_finish_called 3:40:42.2363848 PM boinc.exe 4004 CloseFile C:\ProgramData\BOINC\slots\0 SUCCESS 3:40:52.3762008 PM boinc.exe 4004 CreateFile C:\ProgramData\BOINC\slots\0 SUCCESS Desired Access: Read Data/List Directory, Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened 3:40:52.3763259 PM boinc.exe 4004 QueryDirectory C:\ProgramData\BOINC\slots\0\boinc_finish_called NO SUCH FILE Filter: boinc_finish_called 3:40:52.3763505 PM boinc.exe 4004 CloseFile C:\ProgramData\BOINC\slots\0 SUCCESS 3:41:02.5163450 PM boinc.exe 4004 CreateFile C:\ProgramData\BOINC\slots\0 SUCCESS Desired Access: Read Data/List Directory, Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened 3:41:02.5164890 PM boinc.exe 4004 QueryDirectory C:\ProgramData\BOINC\slots\0\boinc_finish_called NO SUCH FILE Filter: boinc_finish_called 3:41:02.5165140 PM boinc.exe 4004 CloseFile C:\ProgramData\BOINC\slots\0 SUCCESS 3:41:12.6561912 PM boinc.exe 4004 CreateFile C:\ProgramData\BOINC\slots\0 SUCCESS Desired Access: Read Data/List Directory, Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened 3:41:12.6563173 PM boinc.exe 4004 QueryDirectory C:\ProgramData\BOINC\slots\0\boinc_finish_called NO SUCH FILE Filter: boinc_finish_called 3:41:12.6563415 PM boinc.exe 4004 CloseFile C:\ProgramData\BOINC\slots\0 SUCCESS 3:41:22.7966606 PM boinc.exe 4004 CreateFile C:\ProgramData\BOINC\slots\0 SUCCESS Desired Access: Read Data/List Directory, Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened 3:41:22.7968126 PM boinc.exe 4004 QueryDirectory C:\ProgramData\BOINC\slots\0\boinc_finish_called NO SUCH FILE Filter: boinc_finish_called 3:41:22.7968415 PM boinc.exe 4004 CloseFile C:\ProgramData\BOINC\slots\0 SUCCESS 3:41:29.5123043 PM AP7_win_x86_SSE2_OpenCL_NV_r2721.exe 1376 CreateFile C:\ProgramData\BOINC\slots\0\pulse.out1 SUCCESS Desired Access: Generic Write, Read Attributes, Disposition: OverwriteIf, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: Read, Write, AllocationSize: 0, OpenResult: Overwritten 3:41:29.5132436 PM AP7_win_x86_SSE2_OpenCL_NV_r2721.exe 1376 QueryStandardInformationFile C:\ProgramData\BOINC\slots\0\pulse.out1 SUCCESS AllocationSize: 0, EndOfFile: 0, NumberOfLinks: 1, DeletePending: False, Directory: False 3:41:29.5132877 PM AP7_win_x86_SSE2_OpenCL_NV_r2721.exe 1376 FlushBuffersFile C:\ProgramData\BOINC\slots\0\pulse.out1 SUCCESS 3:41:29.5184970 PM AP7_win_x86_SSE2_OpenCL_NV_r2721.exe 1376 WriteFile C:\ProgramData\BOINC\slots\0\pulse.out1 SUCCESS Offset: 0, Length: 5,119, Priority: Normal 3:41:29.5214604 PM AP7_win_x86_SSE2_OpenCL_NV_r2721.exe 1376 WriteFile C:\ProgramData\BOINC\slots\0\pulse.out1 SUCCESS Offset: 5,119, Length: 5,119, Priority: Normal 3:41:29.5215354 PM AP7_win_x86_SSE2_OpenCL_NV_r2721.exe 1376 WriteFile C:\ProgramData\BOINC\slots\0\pulse.out1 SUCCESS Offset: 10,238, Length: 5,120 3:41:29.5215921 PM AP7_win_x86_SSE2_OpenCL_NV_r2721.exe 1376 WriteFile C:\ProgramData\BOINC\slots\0\pulse.out1 SUCCESS Offset: 15,358, Length: 5,119, Priority: Normal 3:41:29.5216564 PM AP7_win_x86_SSE2_OpenCL_NV_r2721.exe 1376 WriteFile C:\ProgramData\BOINC\slots\0\pulse.out1 SUCCESS Offset: 20,477, Length: 5,119 3:41:29.5216951 PM AP7_win_x86_SSE2_OpenCL_NV_r2721.exe 1376 WriteFile C:\ProgramData\BOINC\slots\0\pulse.out1 SUCCESS Offset: 25,596, Length: 3,969 3:41:29.5217326 PM AP7_win_x86_SSE2_OpenCL_NV_r2721.exe 1376 WriteFile C:\ProgramData\BOINC\slots\0\pulse.out1 SUCCESS Offset: 29,565, Length: 392 3:41:29.5217550 PM AP7_win_x86_SSE2_OpenCL_NV_r2721.exe 1376 FlushBuffersFile C:\ProgramData\BOINC\slots\0\pulse.out1 SUCCESS 3:41:29.5217895 PM AP7_win_x86_SSE2_OpenCL_NV_r2721.exe 1376 WriteFile C:\ProgramData\BOINC\slots\0\pulse.out1 SUCCESS Offset: 0, Length: 32,768, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O, Priority: Normal 3:41:29.5223936 PM AP7_win_x86_SSE2_OpenCL_NV_r2721.exe 1376 FlushBuffersFile C:\ProgramData\BOINC\slots\0\pulse.out1 SUCCESS 3:41:29.5224309 PM AP7_win_x86_SSE2_OpenCL_NV_r2721.exe 1376 CloseFile C:\ProgramData\BOINC\slots\0\pulse.out1 SUCCESS 3:41:29.5683572 PM AP7_win_x86_SSE2_OpenCL_NV_r2721.exe 1376 WriteFile C:\ProgramData\BOINC\slots\0\ap_state.dat1 SUCCESS Offset: 0, Length: 4,096 3:41:29.5684172 PM AP7_win_x86_SSE2_OpenCL_NV_r2721.exe 1376 WriteFile C:\ProgramData\BOINC\slots\0\ap_state.dat1 SUCCESS Offset: 4,096, Length: 3,784 3:41:29.5684440 PM AP7_win_x86_SSE2_OpenCL_NV_r2721.exe 1376 FlushBuffersFile C:\ProgramData\BOINC\slots\0\ap_state.dat1 SUCCESS 3:41:29.5684756 PM AP7_win_x86_SSE2_OpenCL_NV_r2721.exe 1376 WriteFile C:\ProgramData\BOINC\slots\0\ap_state.dat1 SUCCESS Offset: 0, Length: 8,192, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O, Priority: Normal 3:41:29.6830620 PM AP7_win_x86_SSE2_OpenCL_NV_r2721.exe 1376 CreateFile C:\ProgramData\BOINC\slots\0 SUCCESS Desired Access: Read Data/List Directory, Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened Then selecting one of the events, I get: Event Detail High Resolution Date & Time: 7/13/2015 3:41:29.5123043 PM Event Class: File System Operation: CreateFile Result: SUCCESS Path: C:\ProgramData\BOINC\slots\0\pulse.out1 TID: 5392 Duration: 0.0009531 Desired Access: Generic Write, Read Attributes Disposition: OverwriteIf Options: Synchronous IO Non-Alert, Non-Directory File Attributes: N ShareMode: Read, Write AllocationSize: 0 OpenResult: Overwritten Process Detail Description: Company: Name: AP7_win_x86_SSE2_OpenCL_NV_r2721.exe Version: Path: C:\ProgramData\BOINC\projects\setiathome.berkeley.edu\AP7_win_x86_SSE2_OpenCL_NV_r2721.exe Command Line: projects/setiathome.berkeley.edu/AP7_win_x86_SSE2_OpenCL_NV_r2721.exe --device 0 PID: 1376 Parent PID: 4004 Session ID: 1 User: jrbuck-PC\jrbuck Auth ID: 00000000:0002268e Architecture: 32-bit Virtualized: False Integrity: High Started: 7/13/2015 11:55:45 AM Ended: (Running) Modules: AP7_win_x86_SSE2_OpenCL_NV_r2721.exe 0x400000 0x118000 C:\ProgramData\BOINC\projects\setiathome.berkeley.edu\AP7_win_x86_SSE2_OpenCL_NV_r2721.exe 10/11/2014 2:42:14 PM nvopencl.dll 0x60e70000 0x96a000 C:\Windows\System32\nvopencl.dll NVIDIA Corporation 8.17.13.3788 5/19/2014 4:13:38 PM libfftw3f-3-3-4_x86.dll 0x63740000 0x1f8000 C:\ProgramData\BOINC\projects\setiathome.berkeley.edu\libfftw3f-3-3-4_x86.dll 3/15/2014 2:27:17 PM OpenCL.dll 0x6ebe0000 0xf000 C:\Windows\system32\OpenCL.dll Khronos Group 1.0.0 5/19/2014 4:13:39 PM nvapi.dll 0x737f0000 0x2be000 C:\Windows\system32\nvapi.dll NVIDIA Corporation 9.18.13.3788 5/19/2014 4:01:51 PM OLEACC.dll 0x747e0000 0x3e000 C:\Windows\system32\OLEACC.dll Microsoft Corporation 7.0.6002.18508 (vistasp2_gdr.110825-0338) 8/25/2011 9:14:26 AM WINMM.dll 0x74820000 0x32000 C:\Windows\system32\WINMM.dll Microsoft Corporation 6.0.6000.16386 (vista_rtm.061101-2205) 10/14/2011 9:04:32 AM comctl32.dll 0x75370000 0x19e000 C:\Windows\WinSxS\x86_microsoft.windows.common-controls_6595b64144ccf1df_6.0.6002.19373_none_5cbe60a608848a19\comctl32.dll Microsoft Corporation 6.10 (longhorn_rtm.080118-1840) 4/24/2015 8:59:23 AM WINTRUST.dll 0x75530000 0x2d000 C:\Windows\system32\WINTRUST.dll Microsoft Corporation 6.0.6002.18881 (vistasp2_gdr.130707-1535) 7/7/2013 9:21:30 PM VERSION.dll 0x75a70000 0x8000 C:\Windows\system32\VERSION.dll Microsoft Corporation 6.0.6002.18005 (lh_sp2rtm.090410-1830) 4/10/2009 11:26:26 PM CRYPT32.dll 0x75d50000 0xf5000 C:\Windows\system32\CRYPT32.dll Microsoft Corporation 6.0.6002.18953 (vistasp2_gdr.131003-0203) 10/3/2013 5:50:39 AM MSASN1.dll 0x75eb0000 0x12000 C:\Windows\system32\MSASN1.dll Microsoft Corporation 6.0.6002.18106 (vistasp2_gdr.090903-2340) 9/4/2009 4:42:13 AM Secur32.dll 0x762b0000 0x14000 C:\Windows\system32\Secur32.dll Microsoft Corporation 6.0.6002.18541 (vistasp2_gdr.111116-0305) 11/16/2011 9:23:48 AM USERENV.dll 0x762d0000 0x1e000 C:\Windows\system32\USERENV.dll Microsoft Corporation 6.0.6000.16386 (vista_rtm.061101-2205) 4/10/2009 11:26:24 PM msvcrt.dll 0x76420000 0xaa000 C:\Windows\system32\msvcrt.dll Microsoft Corporation 7.0.6002.18551 (vistasp2_gdr.111214-0301) 12/14/2011 9:18:34 AM SHLWAPI.dll 0x76550000 0x59000 C:\Windows\system32\SHLWAPI.dll Microsoft Corporation 6.0.6000.16386 (vista_rtm.061101-2205) 11/21/2012 8:54:37 PM OLEAUT32.dll 0x76640000 0x8e000 C:\Windows\system32\OLEAUT32.dll Microsoft Corporation 6.0.6002.19243 11/25/2014 7:06:18 PM GDI32.dll 0x766d0000 0x4c000 C:\Windows\system32\GDI32.dll Microsoft Corporation 6.0.6002.19331 (vistasp2_gdr.150304-1515) 3/4/2015 7:24:11 PM IMM32.DLL 0x769b0000 0x1e000 C:\Windows\system32\IMM32.DLL Microsoft Corporation 6.0.6002.18005 (lh_sp2rtm.090410-1830) 4/10/2009 11:24:14 PM WS2_32.dll 0x769d0000 0x2d000 C:\Windows\system32\WS2_32.dll Microsoft Corporation 6.0.6000.16386 (vista_rtm.061101-2205) 1/19/2008 12:32:40 AM LPK.DLL 0x76a00000 0x9000 C:\Windows\system32\LPK.DLL Microsoft Corporation 6.0.6002.18051 (vistasp2_gdr.090615-0258) 6/15/2009 7:52:47 AM ole32.dll 0x76a10000 0x145000 C:\Windows\system32\ole32.dll Microsoft Corporation 6.0.6000.16386 (vista_rtm.061101-2205) 6/28/2010 10:00:46 AM SETUPAPI.dll 0x76b60000 0x18a000 C:\Windows\system32\SETUPAPI.dll Microsoft Corporation 6.0.6001.18000 (longhorn_rtm.080118-1840) 4/10/2009 11:25:45 PM ADVAPI32.dll 0x76cf0000 0xc6000 C:\Windows\system32\ADVAPI32.dll Microsoft Corporation 6.0.6002.18005 (lh_sp2rtm.090410-1830) 4/10/2009 11:22:15 PM MSCTF.dll 0x76dc0000 0xc8000 C:\Windows\system32\MSCTF.dll Microsoft Corporation 6.0.6000.16386 (vista_rtm.061101-2205) 1/20/2015 7:03:16 PM USER32.dll 0x76e90000 0x9d000 C:\Windows\system32\USER32.dll Microsoft Corporation 6.0.6001.18000 (longhorn_rtm.080118-1840) 4/10/2009 11:26:22 PM USP10.dll 0x76f30000 0x7d000 C:\Windows\system32\USP10.dll Microsoft Corporation 1.0626.6002.19096 (vistasp2_gdr.140426-0532) 4/26/2014 9:01:35 AM SHELL32.dll 0x76fb0000 0xb11000 C:\Windows\system32\SHELL32.dll Microsoft Corporation 6.0.6001.18000 (longhorn_rtm.080118-1840) 2/17/2015 7:02:57 PM RPCRT4.dll 0x77c90000 0xc2000 C:\Windows\system32\RPCRT4.dll Microsoft Corporation 6.0.6001.18000 (longhorn_rtm.080118-1840) 7/10/2013 2:47:08 AM ntdll.dll 0x77d60000 0x128000 C:\Windows\system32\ntdll.dll Microsoft Corporation 6.0.6001.18000 (longhorn_rtm.080118-1840) 3/12/2015 6:46:28 PM imagehlp.dll 0x77e90000 0x2a000 C:\Windows\system32\imagehlp.dll Microsoft Corporation 6.0.6002.18971 (vistasp2_gdr.131021-2034) 10/22/2013 12:21:23 AM NSI.dll 0x77ed0000 0x6000 C:\Windows\system32\NSI.dll Microsoft Corporation 6.0.6001.18000 (longhorn_rtm.080118-1840) 1/19/2008 12:32:52 AM kernel32.dll 0x77ee0000 0xdd000 C:\Windows\system32\kernel32.dll Microsoft Corporation 6.0.6001.18000 (longhorn_rtm.080118-1840) 5/8/2015 4:11:28 PM Stack Detail 0 fltmgr.sys FltRequestOperationStatusCallback + 0xd4b 0x8079b809 C:\Windows\system32\drivers\fltmgr.sys 1 fltmgr.sys FltGetIrpName + 0x774 0x8079dff8 C:\Windows\system32\drivers\fltmgr.sys 2 fltmgr.sys FltDeletePushLock + 0x1734 0x807b0fc0 C:\Windows\system32\drivers\fltmgr.sys 3 fltmgr.sys FltDeletePushLock + 0x1da5 0x807b1631 C:\Windows\system32\drivers\fltmgr.sys 4 ntkrnlpa.exe IofCallDriver + 0x64 0x8324d99a C:\Windows\system32\ntkrnlpa.exe 5 ntkrnlpa.exe CcMapData + 0x134b 0x834488ee C:\Windows\system32\ntkrnlpa.exe 6 ntkrnlpa.exe IoCheckShareAccessEx + 0x176 0x8344b561 C:\Windows\system32\ntkrnlpa.exe 7 ntkrnlpa.exe SeUnlockSubjectContext + 0x1a6 0x83436885 C:\Windows\system32\ntkrnlpa.exe 8 ntkrnlpa.exe ObOpenObjectByName + 0x13c 0x834442ad C:\Windows\system32\ntkrnlpa.exe 9 ntkrnlpa.exe SeSetAccessStateGenericMapping + 0x7a2 0x834499f5 C:\Windows\system32\ntkrnlpa.exe 10 ntkrnlpa.exe NtCreateFile + 0x34 0x8344b5a7 C:\Windows\system32\ntkrnlpa.exe 11 ntkrnlpa.exe ZwQueryLicenseValue + 0xbee 0x83253c46 C:\Windows\system32\ntkrnlpa.exe 12 ntdll.dll ZwCreateFile + 0xc 0x77dc40dc C:\Windows\system32\ntdll.dll 13 kernel32.dll CreateFileW + 0x1bd 0x77f2b368 C:\Windows\system32\kernel32.dll 14 kernel32.dll CreateFileA + 0x2f 0x77f2d16e C:\Windows\system32\kernel32.dll 15 AP7_win_x86_SSE2_OpenCL_NV_r2721.exe AP7_win_x86_SSE2_OpenCL_NV_r2721.exe + 0x8ffec 0x48ffec C:\ProgramData\BOINC\projects\setiathome.berkeley.edu\AP7_win_x86_SSE2_OpenCL_NV_r2721.exe 16 AP7_win_x86_SSE2_OpenCL_NV_r2721.exe AP7_win_x86_SSE2_OpenCL_NV_r2721.exe + 0x90551 0x490551 C:\ProgramData\BOINC\projects\setiathome.berkeley.edu\AP7_win_x86_SSE2_OpenCL_NV_r2721.exe 17 AP7_win_x86_SSE2_OpenCL_NV_r2721.exe AP7_win_x86_SSE2_OpenCL_NV_r2721.exe + 0x905c1 0x4905c1 C:\ProgramData\BOINC\projects\setiathome.berkeley.edu\AP7_win_x86_SSE2_OpenCL_NV_r2721.exe 18 AP7_win_x86_SSE2_OpenCL_NV_r2721.exe AP7_win_x86_SSE2_OpenCL_NV_r2721.exe + 0x8faff 0x48faff C:\ProgramData\BOINC\projects\setiathome.berkeley.edu\AP7_win_x86_SSE2_OpenCL_NV_r2721.exe 19 AP7_win_x86_SSE2_OpenCL_NV_r2721.exe AP7_win_x86_SSE2_OpenCL_NV_r2721.exe + 0x7ebe2 0x47ebe2 C:\ProgramData\BOINC\projects\setiathome.berkeley.edu\AP7_win_x86_SSE2_OpenCL_NV_r2721.exe 20 AP7_win_x86_SSE2_OpenCL_NV_r2721.exe AP7_win_x86_SSE2_OpenCL_NV_r2721.exe + 0x7ec19 0x47ec19 C:\ProgramData\BOINC\projects\setiathome.berkeley.edu\AP7_win_x86_SSE2_OpenCL_NV_r2721.exe 21 AP7_win_x86_SSE2_OpenCL_NV_r2721.exe AP7_win_x86_SSE2_OpenCL_NV_r2721.exe + 0x5e0b9 0x45e0b9 C:\ProgramData\BOINC\projects\setiathome.berkeley.edu\AP7_win_x86_SSE2_OpenCL_NV_r2721.exe 22 AP7_win_x86_SSE2_OpenCL_NV_r2721.exe AP7_win_x86_SSE2_OpenCL_NV_r2721.exe + 0x5f374 0x45f374 C:\ProgramData\BOINC\projects\setiathome.berkeley.edu\AP7_win_x86_SSE2_OpenCL_NV_r2721.exe 23 AP7_win_x86_SSE2_OpenCL_NV_r2721.exe AP7_win_x86_SSE2_OpenCL_NV_r2721.exe + 0xd694 0x40d694 C:\ProgramData\BOINC\projects\setiathome.berkeley.edu\AP7_win_x86_SSE2_OpenCL_NV_r2721.exe 24 AP7_win_x86_SSE2_OpenCL_NV_r2721.exe AP7_win_x86_SSE2_OpenCL_NV_r2721.exe + 0x534a 0x40534a C:\ProgramData\BOINC\projects\setiathome.berkeley.edu\AP7_win_x86_SSE2_OpenCL_NV_r2721.exe So, does this sort of info look like it might be useful? |
Jeff Buck Send message Joined: 11 Feb 00 Posts: 1441 Credit: 148,764,870 RAC: 0 |
Quick update before I turn in. Process Monitor is running on both the xw9400 and T7400 tonight, with a filter set to (hopefully) capture all the file system activity on the BOINC slot folders. If that works successfully, I should be able to correlate any truncated/empty Stderrs with the Process Monitor logs in the morning (Left Coast time). Don't know if I'll be able to do that, though, before the outage starts. We'll see. |
jason_gee Send message Joined: 24 Nov 06 Posts: 7489 Credit: 91,093,184 RAC: 0 |
[So, does this sort of info look like it might be useful? Sure does. Once the wacky behaviour appears, the sequencing, whichever unlink or lack of buffer flush and/or file close or combination, is spotted in the outer log, should simply say in some detail 'the file was already open by another process' or similar' (which is the 32 IIRC). There's two main possibilities there (aside from some malware or AV scanner being rude) The file is really still open (was never closed, i.e. fully committed to disk), with the improperly terminated process hanging onto the write lock on stderr until the OS gets around to cleaning it up, or Boinc's reading there & failing, but still deciding to put whitespace in and give up on the read without ever reading it properly. Since the first condition is known via commit mode builds and Boinc says it looks like the second, I'm contending it's the same problem depending on where you're standing. Ideally the client should be more patient, AND, the application commit and Terminate properly, which is the kindof synchronisation we'd like to see. Once something viable (wacky enough) looking is found, it can be compared to a normal run with same app, and a commit mode application sequence (which should leave out certain steps). There'll be differences in what gets finished and what doesn't. Importantly there are at least two sides to any race condition, and either of both not synchronising is the fault of the whole race organisers. All sorts of nonsensical outcomes are possible. "Living by the wisdom of computer science doesn't sound so bad after all. And unlike most advice, it's backed up by proofs." -- Algorithms to live by: The computer science of human decisions. |
jason_gee Send message Joined: 24 Nov 06 Posts: 7489 Credit: 91,093,184 RAC: 0 |
It'd be especially interesting down the line, and I suspect it'd take practice, to see how far into the nonsensical code after TerminateProcess() the application gets (there's a 1 second sleep and a hard crash). Invoking the boinc debugger to start writing stuff to stderr while the process is shutting down is just plain desperation. "Living by the wisdom of computer science doesn't sound so bad after all. And unlike most advice, it's backed up by proofs." -- Algorithms to live by: The computer science of human decisions. |
Richard Haselgrove Send message Joined: 4 Jul 99 Posts: 14677 Credit: 200,643,578 RAC: 874 |
I've just spent a very boring morning watching Milkyway slots, and eventually got this. The task is 1187645054, which is what we're calling 'truncated'. Unfortunately, this time I didn't manage to get both the screenshot and a copy of the file - the slot was recycled too quickly. I'm currently running Milkyway 3-up, and in this configuration the shorty 'Modified Fit' tasks run for ~140 seconds - 139, in this case. During that time, they first write six files to the slot directory. stderr.txt is always present in the initial six files, but Windows Explorer may display the size as anything between 0KB and 3KB. Whatever Windows Explorer may say, Notepad always shows the contents of the file as being like the truncated stderr in this task, but with the final line as 'Initial wait: 12 ms'. During the 140 second run, the tasks checkpoint twice: first creating, and then updating, two additional files (checkpoint and task_state). Even after the second checkpoint, stderr still ends at 'Initial wait: 12 ms'. In the final second of the run, the files visible in Windows Explorer first update, and then are replaced by the initial six files for the next task. It's very difficult to monitor and capture what happens in this phase - it all happens in less than a second - and sometimes the intermediate update isn't reflected in Windows Explorer at all. But by sitting with my finger over the button, and twitching when it did, I opened a stderr in mid-write (notepad is non-blocking, and happy to do the same 'read access shared' that BOINC does), and saw it ending ... (like the one which errored). But that was at 11:22 local, and the figures match task 1187681220 - which validated, with additional result data below what I saw. The figures are not the same as the 'validate error' task 1187685261 which reported a few minutes later, but while my screen was already full with other windows. |
Jeff Buck Send message Joined: 11 Feb 00 Posts: 1441 Credit: 148,764,870 RAC: 0 |
Okay, here's my first crack at trying to throw Process Monitor log info into the mix for a truncated Stderr. The task is 4263730792, on my xw9400. And right up front I'll say, I don't think I see a smoking gun. The Stderr on the Task Detail page looks like: <core_client_version>7.6.2</core_client_version> <![CDATA[ <stderr_txt> setiathome_CUDA: Found 4 CUDA device(s): Device 1: GeForce GTX 750 Ti, 2047 MiB, regsPerBlock 65536 computeCap 5.0, multiProcs 5 pciBusID = 5, pciSlotID = 0 Device 2: GeForce GTX 660, 2047 MiB, regsPerBlock 65536 computeCap 3.0, multiProcs 5 pciBusID = 88, pciSlotID = 0 Device 3: GeForce GTX 750 Ti, 2047 MiB, regsPerBlock 65536 computeCap 5.0, multiProcs 5 pciBusID = 69, pciSlotID = 0 Device 4: GeForce GTX 660, 1535 MiB, regsPerBlock 65536 computeCap 3.0, multiProcs 6 pciBusID = 24, pciSlotID = 0 In cudaAcc_initializeDevice(): Boinc passed DevPref 2 setiathome_CUDA: CUDA Device 2 specified, checking... Device 2: GeForce GTX 660 is okay SETI@home using CUDA accelerated device GeForce GTX 660 mbcuda.cfg, processpriority key detected pulsefind: blocks per SM 4 (Fermi or newer default) pulsefind: periods per launch 100 (default) Priority of process set to ABOVE_NORMAL successfully Priority of worker thread set successfully setiathome enhanced x41zc, Cuda 5.00 Detected setiathome_enhanced_v7 task. Autocorrelations enabled, size 128k elements. Work Unit Info: ............... WU true angle range is : 0.430424 Kepler GPU current clockRate = 1162 MHz re-using dev_GaussFitResults array for dev_AutoCorrIn, 4194304 bytes re-using dev_GaussFitResults+524288x8 array for dev_AutoCorrOut, 4194304 bytes Thread call stack limit is: 1k </stderr_txt> ]]> The relevant BOINC Event Log lines: 13-Jul-2015 23:26:10 [SETI@home] [task] Process for 01jn15ab.1817.92674.438086664204.12.191_1 exited, exit code 0, task state 1 13-Jul-2015 23:26:10 [SETI@home] [task] task_state=EXITED for 01jn15ab.1817.92674.438086664204.12.191_1 from handle_exited_app 13-Jul-2015 23:26:10 [---] [slot] cleaning out slots/2: handle_exited_app() 13-Jul-2015 23:26:10 [---] [slot] removed file slots/2/boinc_finish_called 13-Jul-2015 23:26:10 [---] [slot] removed file slots/2/boinc_task_state.xml 13-Jul-2015 23:26:10 [---] [slot] removed file slots/2/cudart32_50_35.dll 13-Jul-2015 23:26:10 [---] [slot] removed file slots/2/cufft32_50_35.dll 13-Jul-2015 23:26:10 [---] [slot] removed file slots/2/init_data.xml 13-Jul-2015 23:26:10 [---] [slot] removed file slots/2/Lunatics_x41zc_win32_cuda50.exe 13-Jul-2015 23:26:10 [---] [slot] removed file slots/2/mbcuda.cfg 13-Jul-2015 23:26:10 [---] [slot] removed file slots/2/result.sah 13-Jul-2015 23:26:10 [---] [slot] removed file slots/2/state.sah 13-Jul-2015 23:26:10 [---] [slot] removed file slots/2/stderr.txt 13-Jul-2015 23:26:10 [---] [slot] removed file slots/2/work_unit.sah 13-Jul-2015 23:26:10 [SETI@home] Computation for task 01jn15ab.1817.92674.438086664204.12.191_1 finished 13-Jul-2015 23:26:10 [SETI@home] [task] result state=FILES_UPLOADING for 01jn15ab.1817.92674.438086664204.12.191_1 from CS::app_finished 13-Jul-2015 23:26:10 [---] [slot] cleaning out slots/2: get_free_slot() 13-Jul-2015 23:26:10 [SETI@home] [slot] assigning slot 2 to 01jn15ab.1817.92674.438086664204.12.181_0 13-Jul-2015 23:26:10 [---] [slot] removed file slots/2/init_data.xml 13-Jul-2015 23:26:10 [SETI@home] [slot] linked ../../projects/setiathome.berkeley.edu/Lunatics_x41zc_win32_cuda50.exe to slots/2/Lunatics_x41zc_win32_cuda50.exe 13-Jul-2015 23:26:10 [SETI@home] [slot] linked ../../projects/setiathome.berkeley.edu/cudart32_50_35.dll to slots/2/cudart32_50_35.dll 13-Jul-2015 23:26:10 [SETI@home] [slot] linked ../../projects/setiathome.berkeley.edu/cufft32_50_35.dll to slots/2/cufft32_50_35.dll 13-Jul-2015 23:26:10 [SETI@home] [slot] linked ../../projects/setiathome.berkeley.edu/mbcuda.cfg to slots/2/mbcuda.cfg 13-Jul-2015 23:26:10 [SETI@home] [slot] linked ../../projects/setiathome.berkeley.edu/01jn15ab.1817.92674.438086664204.12.181 to slots/2/work_unit.sah 13-Jul-2015 23:26:10 [SETI@home] [slot] linked ../../projects/setiathome.berkeley.edu/01jn15ab.1817.92674.438086664204.12.181_0_0 to slots/2/result.sah 13-Jul-2015 23:26:10 [---] [slot] removed file slots/2/boinc_temporary_exit 13-Jul-2015 23:26:10 [SETI@home] [task] task_state=EXECUTING for 01jn15ab.1817.92674.438086664204.12.181_0 from start 13-Jul-2015 23:26:10 [SETI@home] Starting task 01jn15ab.1817.92674.438086664204.12.181_0 13-Jul-2015 23:26:10 [SETI@home] [cpu_sched] Starting task 01jn15ab.1817.92674.438086664204.12.181_0 using setiathome_v7 version 700 (cuda50) in slot 2 13-Jul-2015 23:26:12 [SETI@home] Started upload of 01jn15ab.1817.92674.438086664204.12.191_1_0 13-Jul-2015 23:26:15 [SETI@home] Finished upload of 01jn15ab.1817.92674.438086664204.12.191_1_0 Note that the BOINC Event Log shows no remove/unlink failures. The PM log entries for the 23:26:10 (11:26:10 PM) time period total 1372 lines, so I'll abridge them somewhat and try to break them down into digestible chunks, starting with: 11:26:10.0739649 PM Lunatics_x41zc_win32_cuda50.exe 2540 QueryStandardInformationFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\stderr.txt SUCCESS AllocationSize: 4,096, EndOfFile: 1,434, NumberOfLinks: 1, DeletePending: False, Directory: False 11:26:10.0742274 PM Lunatics_x41zc_win32_cuda50.exe 2540 WriteFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\stderr.txt SUCCESS Offset: 1,434, Length: 1 11:26:10.0743752 PM Lunatics_x41zc_win32_cuda50.exe 2540 QueryStandardInformationFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\stderr.txt SUCCESS AllocationSize: 4,096, EndOfFile: 1,435, NumberOfLinks: 1, DeletePending: False, Directory: False 11:26:10.0746120 PM Lunatics_x41zc_win32_cuda50.exe 2540 WriteFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\stderr.txt SUCCESS Offset: 1,435, Length: 1(Skipping 748 lines virtually identical to the above, except for "Length: 2" on a handful of them, perhaps CRLF writes.) 11:26:10.2477743 PM Lunatics_x41zc_win32_cuda50.exe 2540 QueryStandardInformationFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\stderr.txt SUCCESS AllocationSize: 4,096, EndOfFile: 1,824, NumberOfLinks: 1, DeletePending: False, Directory: False 11:26:10.2479524 PM Lunatics_x41zc_win32_cuda50.exe 2540 WriteFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\stderr.txt SUCCESS Offset: 1,824, Length: 1 11:26:10.2480959 PM Lunatics_x41zc_win32_cuda50.exe 2540 QueryStandardInformationFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\stderr.txt SUCCESS AllocationSize: 4,096, EndOfFile: 1,825, NumberOfLinks: 1, DeletePending: False, Directory: False 11:26:10.2482866 PM Lunatics_x41zc_win32_cuda50.exe 2540 WriteFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\stderr.txt SUCCESS Offset: 1,825, Length: 2 11:26:10.2485159 PM Lunatics_x41zc_win32_cuda50.exe 2540 CreateFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\boinc_finish_called SUCCESS Desired Access: Generic Write, Read Attributes, Disposition: OverwriteIf, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: Read, Write, AllocationSize: 0, OpenResult: Created 11:26:10.2486207 PM Lunatics_x41zc_win32_cuda50.exe 2540 CreateFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS Desired Access: Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Open For Backup, Attributes: N, ShareMode: Read, Write, AllocationSize: n/a, OpenResult: Opened 11:26:10.2486915 PM Lunatics_x41zc_win32_cuda50.exe 2540 CloseFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS 11:26:10.2493512 PM Lunatics_x41zc_win32_cuda50.exe 2540 CloseFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\boinc_finish_called SUCCESS 11:26:10.2496275 PM Lunatics_x41zc_win32_cuda50.exe 2540 CreateFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\init_data.xml SUCCESS Desired Access: Generic Write, Read Attributes, Disposition: OverwriteIf, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: Read, Write, AllocationSize: 0, OpenResult: Overwritten 11:26:10.2497340 PM Lunatics_x41zc_win32_cuda50.exe 2540 CreateFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS Desired Access: Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Open For Backup, Attributes: N, ShareMode: Read, Write, AllocationSize: n/a, OpenResult: Opened 11:26:10.2498098 PM Lunatics_x41zc_win32_cuda50.exe 2540 CloseFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS 11:26:10.2503674 PM Lunatics_x41zc_win32_cuda50.exe 2540 WriteFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\init_data.xml SUCCESS Offset: 0, Length: 1,024 11:26:10.2506021 PM Lunatics_x41zc_win32_cuda50.exe 2540 WriteFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\init_data.xml SUCCESS Offset: 1,024, Length: 1,024 11:26:10.2507467 PM Lunatics_x41zc_win32_cuda50.exe 2540 WriteFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\init_data.xml SUCCESS Offset: 2,048, Length: 1,024 11:26:10.2508890 PM Lunatics_x41zc_win32_cuda50.exe 2540 WriteFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\init_data.xml SUCCESS Offset: 3,072, Length: 1,024 11:26:10.2510274 PM Lunatics_x41zc_win32_cuda50.exe 2540 WriteFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\init_data.xml SUCCESS Offset: 4,096, Length: 95 11:26:10.2512798 PM Lunatics_x41zc_win32_cuda50.exe 2540 WriteFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\init_data.xml SUCCESS Offset: 4,191, Length: 656 11:26:10.2513566 PM Lunatics_x41zc_win32_cuda50.exe 2540 CloseFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\init_data.xml SUCCESS 11:26:10.2520175 PM MsMpEng.exe 1264 CreateFileMapping C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\init_data.xml SUCCESS SyncType: SyncTypeCreateSection, PageProtection: PAGE_READONLY 11:26:10.2520278 PM MsMpEng.exe 1264 QueryStandardInformationFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\init_data.xml SUCCESS AllocationSize: 16,384, EndOfFile: 4,847, NumberOfLinks: 1, DeletePending: False, Directory: False 11:26:10.2521415 PM MsMpEng.exe 1264 CreateFileMapping C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\init_data.xml SUCCESS SyncType: SyncTypeOther 11:26:10.2577194 PM Lunatics_x41zc_win32_cuda50.exe 2540 CloseFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\boinc_lockfile SUCCESS 11:26:10.2578931 PM Lunatics_x41zc_win32_cuda50.exe 2540 CreateFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS Desired Access: Read Data/List Directory, Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write, AllocationSize: n/a, OpenResult: Opened 11:26:10.2579703 PM Lunatics_x41zc_win32_cuda50.exe 2540 QueryDirectory C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\boinc_lockfile SUCCESS Filter: boinc_lockfile, 1: boinc_lockfile 11:26:10.2580632 PM Lunatics_x41zc_win32_cuda50.exe 2540 CloseFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS 11:26:10.2581783 PM Lunatics_x41zc_win32_cuda50.exe 2540 CreateFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\boinc_lockfile SUCCESS Desired Access: Read Attributes, Delete, Disposition: Open, Options: Non-Directory File, Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened 11:26:10.2582612 PM Lunatics_x41zc_win32_cuda50.exe 2540 QueryAttributeTagFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\boinc_lockfile SUCCESS Attributes: A, ReparseTag: 0x0 11:26:10.2583282 PM Lunatics_x41zc_win32_cuda50.exe 2540 SetDispositionInformationFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\boinc_lockfile SUCCESS Delete: True 11:26:10.2583963 PM Lunatics_x41zc_win32_cuda50.exe 2540 CloseFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\boinc_lockfile SUCCESS 11:26:10.2586581 PM Lunatics_x41zc_win32_cuda50.exe 2540 QueryStandardInformationFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\stderr.txt SUCCESS AllocationSize: 4,096, EndOfFile: 1,827, NumberOfLinks: 1, DeletePending: False, Directory: False 11:26:10.2588314 PM Lunatics_x41zc_win32_cuda50.exe 2540 WriteFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\stderr.txt SUCCESS Offset: 1,827, Length: 1 11:26:10.2589223 PM Lunatics_x41zc_win32_cuda50.exe 2540 QueryStandardInformationFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\stderr.txt SUCCESS AllocationSize: 4,096, EndOfFile: 1,828, NumberOfLinks: 1, DeletePending: False, Directory: False 11:26:10.2591427 PM Lunatics_x41zc_win32_cuda50.exe 2540 WriteFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\stderr.txt SUCCESS Offset: 1,828, Length: 1(Skipping 334 lines virtually identical to the above, again with just a handful that have "Length: 2".) 11:26:10.3055805 PM Lunatics_x41zc_win32_cuda50.exe 2540 QueryStandardInformationFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\stderr.txt SUCCESS AllocationSize: 4,096, EndOfFile: 1,999, NumberOfLinks: 1, DeletePending: False, Directory: False 11:26:10.3060566 PM Lunatics_x41zc_win32_cuda50.exe 2540 WriteFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\stderr.txt SUCCESS Offset: 1,999, Length: 1 11:26:10.3062540 PM Lunatics_x41zc_win32_cuda50.exe 2540 QueryStandardInformationFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\stderr.txt SUCCESS AllocationSize: 4,096, EndOfFile: 2,000, NumberOfLinks: 1, DeletePending: False, Directory: False 11:26:10.3064260 PM Lunatics_x41zc_win32_cuda50.exe 2540 WriteFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\stderr.txt SUCCESS Offset: 2,000, Length: 2 11:26:10.3108823 PM Lunatics_x41zc_win32_cuda50.exe 2540 CloseFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS 11:26:10.3110268 PM Lunatics_x41zc_win32_cuda50.exe 2540 CloseFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\stderr.txt SUCCESS 11:26:10.3118383 PM MsMpEng.exe 1264 CreateFileMapping C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\stderr.txt SUCCESS SyncType: SyncTypeCreateSection, PageProtection: PAGE_READONLY 11:26:10.3118543 PM MsMpEng.exe 1264 QueryStandardInformationFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\stderr.txt SUCCESS AllocationSize: 4,096, EndOfFile: 2,002, NumberOfLinks: 1, DeletePending: False, Directory: False The MsMpEng.exe module is the Microsoft Antimalware Service Executable. At this point, the science app appears to be done with Stderr, closing the file with 2,002 bytes. (The Stderr in the Task Detail appears to have 1432 bytes, approximately what seems to be in the stderr.txt file at the beginning of these PM log entries.) At this point is where BOINC seems to take over. 11:26:10.3119482 PM boinc.exe 3612 CreateFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\boinc_finish_called SUCCESS Desired Access: Generic Read, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: Read, Write, AllocationSize: n/a, OpenResult: Opened 11:26:10.3120824 PM MsMpEng.exe 1264 CreateFileMapping C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\stderr.txt SUCCESS SyncType: SyncTypeOther 11:26:10.3121206 PM boinc.exe 3612 ReadFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\boinc_finish_called END OF FILE Offset: 0, Length: 4,096 11:26:10.3121975 PM boinc.exe 3612 ReadFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\boinc_finish_called END OF FILE Offset: 0, Length: 4,096 11:26:10.3122616 PM boinc.exe 3612 ReadFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\boinc_finish_called END OF FILE Offset: 0, Length: 4,096 11:26:10.3123341 PM boinc.exe 3612 CloseFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\boinc_finish_called SUCCESS 11:26:10.3125120 PM boinc.exe 3612 CreateFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS Desired Access: Read Data/List Directory, Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write, AllocationSize: n/a, OpenResult: Opened 11:26:10.3125905 PM boinc.exe 3612 QueryDirectory C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\stderr.txt SUCCESS Filter: stderr.txt, 1: stderr.txt 11:26:10.3126958 PM boinc.exe 3612 CloseFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS 11:26:10.3128127 PM boinc.exe 3612 CreateFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS Desired Access: Read Data/List Directory, Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write, AllocationSize: n/a, OpenResult: Opened 11:26:10.3128816 PM boinc.exe 3612 QueryDirectory C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\stderr.txt SUCCESS Filter: stderr.txt, 1: stderr.txt 11:26:10.3129925 PM boinc.exe 3612 CloseFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS 11:26:10.3131086 PM boinc.exe 3612 CreateFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\stderr.txt SUCCESS Desired Access: Generic Read, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: Read, Write, AllocationSize: n/a, OpenResult: Opened 11:26:10.3169796 PM boinc.exe 3612 ReadFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\stderr.txt SUCCESS Offset: 0, Length: 2,002 11:26:10.3171062 PM boinc.exe 3612 CloseFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\stderr.txt SUCCESS It sure looks to me like BOINC has just read a 2,002 byte stderr.txt file. Now BOINC appears to go into cleanup mode. 11:26:10.3175988 PM boinc.exe 3612 CreateFile C:\Documents and Settings\All Users\Application Data\BOINC\slots SUCCESS Desired Access: Read Data/List Directory, Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write, AllocationSize: n/a, OpenResult: Opened 11:26:10.3176588 PM boinc.exe 3612 QueryDirectory C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS Filter: 2, 1: 2 11:26:10.3177403 PM boinc.exe 3612 CloseFile C:\Documents and Settings\All Users\Application Data\BOINC\slots SUCCESS 11:26:10.3178849 PM boinc.exe 3612 CreateFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS Desired Access: Read Data/List Directory, Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write, AllocationSize: n/a, OpenResult: Opened 11:26:10.3179538 PM boinc.exe 3612 QueryDirectory C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\* SUCCESS Filter: *, 1: . 11:26:10.3180340 PM boinc.exe 3612 QueryDirectory C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS 0: .., 1: boinc_finish_called, 2: boinc_task_state.xml, 3: cudart32_50_35.dll, 4: cufft32_50_35.dll, 5: init_data.xml, 6: Lunatics_x41zc_win32_cuda50.exe, 7: mbcuda.cfg, 8: result.sah, 9: state.sah, 10: stderr.txt, 11: work_unit.sah 11:26:10.3181518 PM boinc.exe 3612 CreateFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS Desired Access: Read Data/List Directory, Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write, AllocationSize: n/a, OpenResult: Opened 11:26:10.3182225 PM boinc.exe 3612 QueryDirectory C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\boinc_finish_called SUCCESS Filter: boinc_finish_called, 1: boinc_finish_called 11:26:10.3182972 PM boinc.exe 3612 CloseFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS 11:26:10.3183935 PM boinc.exe 3612 CreateFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\boinc_finish_called SUCCESS Desired Access: Read Attributes, Delete, Disposition: Open, Options: Non-Directory File, Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened 11:26:10.3184706 PM boinc.exe 3612 QueryAttributeTagFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\boinc_finish_called SUCCESS Attributes: A, ReparseTag: 0x0 11:26:10.3185372 PM boinc.exe 3612 SetDispositionInformationFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\boinc_finish_called SUCCESS Delete: True 11:26:10.3186149 PM boinc.exe 3612 CloseFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\boinc_finish_called SUCCESS 11:26:10.3189049 PM boinc.exe 3612 CreateFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS Desired Access: Read Data/List Directory, Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write, AllocationSize: n/a, OpenResult: Opened 11:26:10.3189721 PM boinc.exe 3612 QueryDirectory C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\boinc_task_state.xml SUCCESS Filter: boinc_task_state.xml, 1: boinc_task_state.xml 11:26:10.3190469 PM boinc.exe 3612 CloseFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS 11:26:10.3191631 PM boinc.exe 3612 CreateFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\boinc_task_state.xml SUCCESS Desired Access: Read Attributes, Delete, Disposition: Open, Options: Non-Directory File, Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened 11:26:10.3192363 PM boinc.exe 3612 QueryAttributeTagFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\boinc_task_state.xml SUCCESS Attributes: A, ReparseTag: 0x0 11:26:10.3193025 PM boinc.exe 3612 SetDispositionInformationFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\boinc_task_state.xml SUCCESS Delete: True 11:26:10.3193711 PM boinc.exe 3612 CloseFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\boinc_task_state.xml SUCCESS 11:26:10.3196762 PM boinc.exe 3612 CreateFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS Desired Access: Read Data/List Directory, Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write, AllocationSize: n/a, OpenResult: Opened 11:26:10.3197459 PM boinc.exe 3612 QueryDirectory C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\cudart32_50_35.dll SUCCESS Filter: cudart32_50_35.dll, 1: cudart32_50_35.dll 11:26:10.3198262 PM boinc.exe 3612 CloseFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS 11:26:10.3199435 PM boinc.exe 3612 CreateFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\cudart32_50_35.dll SUCCESS Desired Access: Read Attributes, Delete, Disposition: Open, Options: Non-Directory File, Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened 11:26:10.3200186 PM boinc.exe 3612 QueryAttributeTagFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\cudart32_50_35.dll SUCCESS Attributes: A, ReparseTag: 0x0 11:26:10.3200883 PM boinc.exe 3612 SetDispositionInformationFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\cudart32_50_35.dll SUCCESS Delete: True 11:26:10.3201678 PM boinc.exe 3612 CloseFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\cudart32_50_35.dll SUCCESS 11:26:10.3204867 PM boinc.exe 3612 CreateFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS Desired Access: Read Data/List Directory, Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write, AllocationSize: n/a, OpenResult: Opened 11:26:10.3205535 PM boinc.exe 3612 QueryDirectory C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\cufft32_50_35.dll SUCCESS Filter: cufft32_50_35.dll, 1: cufft32_50_35.dll 11:26:10.3206297 PM boinc.exe 3612 CloseFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS 11:26:10.3207507 PM boinc.exe 3612 CreateFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\cufft32_50_35.dll SUCCESS Desired Access: Read Attributes, Delete, Disposition: Open, Options: Non-Directory File, Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened 11:26:10.3208234 PM boinc.exe 3612 QueryAttributeTagFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\cufft32_50_35.dll SUCCESS Attributes: A, ReparseTag: 0x0 11:26:10.3208871 PM boinc.exe 3612 SetDispositionInformationFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\cufft32_50_35.dll SUCCESS Delete: True 11:26:10.3209579 PM boinc.exe 3612 CloseFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\cufft32_50_35.dll SUCCESS 11:26:10.3212493 PM boinc.exe 3612 CreateFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS Desired Access: Read Data/List Directory, Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write, AllocationSize: n/a, OpenResult: Opened 11:26:10.3213288 PM boinc.exe 3612 QueryDirectory C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\init_data.xml SUCCESS Filter: init_data.xml, 1: init_data.xml 11:26:10.3214076 PM boinc.exe 3612 CloseFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS 11:26:10.3215204 PM boinc.exe 3612 CreateFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\init_data.xml SUCCESS Desired Access: Read Attributes, Delete, Disposition: Open, Options: Non-Directory File, Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened 11:26:10.3215947 PM boinc.exe 3612 QueryAttributeTagFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\init_data.xml SUCCESS Attributes: A, ReparseTag: 0x0 11:26:10.3216596 PM boinc.exe 3612 SetDispositionInformationFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\init_data.xml SUCCESS Delete: True 11:26:10.3217482 PM boinc.exe 3612 CloseFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\init_data.xml SUCCESS 11:26:10.3220687 PM boinc.exe 3612 CreateFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS Desired Access: Read Data/List Directory, Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write, AllocationSize: n/a, OpenResult: Opened 11:26:10.3223458 PM boinc.exe 3612 QueryDirectory C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\Lunatics_x41zc_win32_cuda50.exe SUCCESS Filter: Lunatics_x41zc_win32_cuda50.exe, 1: Lunatics_x41zc_win32_cuda50.exe 11:26:10.3225282 PM boinc.exe 3612 CloseFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS 11:26:10.3226622 PM boinc.exe 3612 CreateFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\Lunatics_x41zc_win32_cuda50.exe SUCCESS Desired Access: Read Attributes, Delete, Disposition: Open, Options: Non-Directory File, Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened 11:26:10.3227410 PM boinc.exe 3612 QueryAttributeTagFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\Lunatics_x41zc_win32_cuda50.exe SUCCESS Attributes: A, ReparseTag: 0x0 11:26:10.3228080 PM boinc.exe 3612 SetDispositionInformationFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\Lunatics_x41zc_win32_cuda50.exe SUCCESS Delete: True 11:26:10.3228817 PM boinc.exe 3612 CloseFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\Lunatics_x41zc_win32_cuda50.exe SUCCESS 11:26:10.3232806 PM boinc.exe 3612 CreateFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS Desired Access: Read Data/List Directory, Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write, AllocationSize: n/a, OpenResult: Opened 11:26:10.3233618 PM boinc.exe 3612 QueryDirectory C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\mbcuda.cfg SUCCESS Filter: mbcuda.cfg, 1: mbcuda.cfg 11:26:10.3234455 PM boinc.exe 3612 CloseFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS 11:26:10.3235874 PM boinc.exe 3612 CreateFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\mbcuda.cfg SUCCESS Desired Access: Read Attributes, Delete, Disposition: Open, Options: Non-Directory File, Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened 11:26:10.3236809 PM boinc.exe 3612 QueryAttributeTagFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\mbcuda.cfg SUCCESS Attributes: A, ReparseTag: 0x0 11:26:10.3237644 PM boinc.exe 3612 SetDispositionInformationFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\mbcuda.cfg SUCCESS Delete: True 11:26:10.3238533 PM boinc.exe 3612 CloseFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\mbcuda.cfg SUCCESS 11:26:10.3243526 PM boinc.exe 3612 CreateFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS Desired Access: Read Data/List Directory, Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write, AllocationSize: n/a, OpenResult: Opened 11:26:10.3244454 PM boinc.exe 3612 QueryDirectory C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\result.sah SUCCESS Filter: result.sah, 1: result.sah 11:26:10.3245880 PM boinc.exe 3612 CloseFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS 11:26:10.3247414 PM boinc.exe 3612 CreateFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\result.sah SUCCESS Desired Access: Read Attributes, Delete, Disposition: Open, Options: Non-Directory File, Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened 11:26:10.3248464 PM boinc.exe 3612 QueryAttributeTagFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\result.sah SUCCESS Attributes: A, ReparseTag: 0x0 11:26:10.3249932 PM boinc.exe 3612 SetDispositionInformationFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\result.sah SUCCESS Delete: True 11:26:10.3250919 PM boinc.exe 3612 CloseFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\result.sah SUCCESS 11:26:10.3254183 PM boinc.exe 3612 CreateFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS Desired Access: Read Data/List Directory, Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write, AllocationSize: n/a, OpenResult: Opened 11:26:10.3255582 PM boinc.exe 3612 QueryDirectory C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\state.sah SUCCESS Filter: state.sah, 1: state.sah 11:26:10.3256508 PM boinc.exe 3612 CloseFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS 11:26:10.3258048 PM boinc.exe 3612 CreateFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\state.sah SUCCESS Desired Access: Read Attributes, Delete, Disposition: Open, Options: Non-Directory File, Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened 11:26:10.3259000 PM boinc.exe 3612 QueryAttributeTagFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\state.sah SUCCESS Attributes: A, ReparseTag: 0x0 11:26:10.3259790 PM boinc.exe 3612 SetDispositionInformationFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\state.sah SUCCESS Delete: True 11:26:10.3260642 PM boinc.exe 3612 CloseFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\state.sah SUCCESS 11:26:10.3265124 PM boinc.exe 3612 CreateFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS Desired Access: Read Data/List Directory, Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write, AllocationSize: n/a, OpenResult: Opened 11:26:10.3265867 PM boinc.exe 3612 QueryDirectory C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\stderr.txt SUCCESS Filter: stderr.txt, 1: stderr.txt 11:26:10.3268299 PM boinc.exe 3612 CloseFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS 11:26:10.3272052 PM boinc.exe 3612 CreateFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\stderr.txt SUCCESS Desired Access: Read Attributes, Delete, Disposition: Open, Options: Non-Directory File, Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened 11:26:10.3273255 PM boinc.exe 3612 QueryAttributeTagFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\stderr.txt SUCCESS Attributes: A, ReparseTag: 0x0 11:26:10.3274106 PM boinc.exe 3612 SetDispositionInformationFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\stderr.txt SUCCESS Delete: True 11:26:10.3275021 PM boinc.exe 3612 CloseFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\stderr.txt SUCCESS 11:26:10.3278489 PM boinc.exe 3612 CreateFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS Desired Access: Read Data/List Directory, Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write, AllocationSize: n/a, OpenResult: Opened 11:26:10.3281444 PM boinc.exe 3612 QueryDirectory C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\work_unit.sah SUCCESS Filter: work_unit.sah, 1: work_unit.sah 11:26:10.3282607 PM boinc.exe 3612 CloseFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS 11:26:10.3287017 PM boinc.exe 3612 CreateFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\work_unit.sah SUCCESS Desired Access: Read Attributes, Delete, Disposition: Open, Options: Non-Directory File, Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened 11:26:10.3289391 PM boinc.exe 3612 QueryAttributeTagFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\work_unit.sah SUCCESS Attributes: A, ReparseTag: 0x0 11:26:10.3291789 PM boinc.exe 3612 SetDispositionInformationFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\work_unit.sah SUCCESS Delete: True 11:26:10.3292976 PM boinc.exe 3612 CloseFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\work_unit.sah SUCCESS 11:26:10.3299405 PM boinc.exe 3612 QueryDirectory C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 NO MORE FILES 11:26:10.3300428 PM boinc.exe 3612 CloseFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS 11:26:10.3441096 PM boinc.exe 3612 CreateFile C:\Documents and Settings\All Users\Application Data\BOINC\slots SUCCESS Desired Access: Read Data/List Directory, Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write, AllocationSize: n/a, OpenResult: Opened 11:26:10.3441936 PM boinc.exe 3612 QueryDirectory C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS Filter: 2, 1: 2 11:26:10.3443011 PM boinc.exe 3612 CloseFile C:\Documents and Settings\All Users\Application Data\BOINC\slots SUCCESS 11:26:10.3444175 PM boinc.exe 3612 CreateFile C:\Documents and Settings\All Users\Application Data\BOINC\slots SUCCESS Desired Access: Read Data/List Directory, Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write, AllocationSize: n/a, OpenResult: Opened 11:26:10.3444803 PM boinc.exe 3612 QueryDirectory C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS Filter: 2, 1: 2 11:26:10.3445533 PM boinc.exe 3612 CloseFile C:\Documents and Settings\All Users\Application Data\BOINC\slots SUCCESS 11:26:10.3447288 PM boinc.exe 3612 CreateFile C:\Documents and Settings\All Users\Application Data\BOINC\slots SUCCESS Desired Access: Read Data/List Directory, Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write, AllocationSize: n/a, OpenResult: Opened 11:26:10.3447915 PM boinc.exe 3612 QueryDirectory C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS Filter: 2, 1: 2 11:26:10.3448674 PM boinc.exe 3612 CloseFile C:\Documents and Settings\All Users\Application Data\BOINC\slots SUCCESS 11:26:10.3449928 PM boinc.exe 3612 CreateFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS Desired Access: Read Data/List Directory, Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write, AllocationSize: n/a, OpenResult: Opened 11:26:10.3450903 PM boinc.exe 3612 QueryDirectory C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\* SUCCESS Filter: *, 1: . 11:26:10.3451896 PM boinc.exe 3612 QueryDirectory C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS 0: .. 11:26:10.3452841 PM boinc.exe 3612 QueryDirectory C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 NO MORE FILES 11:26:10.3453847 PM boinc.exe 3612 CloseFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS 11:26:10.3455601 PM boinc.exe 3612 CreateFile C:\Documents and Settings\All Users\Application Data\BOINC\slots SUCCESS Desired Access: Read Data/List Directory, Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write, AllocationSize: n/a, OpenResult: Opened 11:26:10.3456250 PM boinc.exe 3612 QueryDirectory C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS Filter: 2, 1: 2 11:26:10.3456992 PM boinc.exe 3612 CloseFile C:\Documents and Settings\All Users\Application Data\BOINC\slots SUCCESS 11:26:10.3458200 PM boinc.exe 3612 CreateFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS Desired Access: Read Data/List Directory, Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write, AllocationSize: n/a, OpenResult: Opened 11:26:10.3459225 PM boinc.exe 3612 QueryDirectory C:\Documents and Settings\All Users\Application Data\BOINC\slots\2\* SUCCESS Filter: *, 1: . 11:26:10.3460067 PM boinc.exe 3612 QueryDirectory C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS 0: .. 11:26:10.3461031 PM boinc.exe 3612 QueryDirectory C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 NO MORE FILES 11:26:10.3461772 PM boinc.exe 3612 CloseFile C:\Documents and Settings\All Users\Application Data\BOINC\slots\2 SUCCESS Subsequent PM entries from this point on for Slot 2 appear to be related to the startup of the next task. To summarize what I think I'm seeing here: 1) The Stderr output on the Task Detail page totals (by my count) 1,432 bytes. 2) In its termination phase, the science app writes additional data to stderr.txt, beginning at offset 1,434, apparently in two separate blocks (albeit seemingly 1 or 2 bytes at a time, rather than a block write), bringing it to a total of 2,002 bytes. Between those two blocks, boinc_finish is called, the result file is written (in buffered blocks) and the boinc_lockfile is deleted. 3) BOINC reads the boinc_finish_called file. 4) BOINC reads the stderr.txt file, apparently all 2,002 bytes of it. 5) BOINC goes into cleaup mode. I sure don't feel like I'm seeing anything out of sequence. HOWEVER, one thing I now realize that I didn't capture in the PM logs, since I set the filter to only look at the Slot folders, is what BOINC is doing with that Stderr file AFTER it's read it. I assume it's updating the client_state file. Could the timing issue be there? Adding another filter to PM could probably capture that additional activity. Of course, this is just one sample. I also have another truncated Stderr on the xw9400 that I can look at, a somewhat unusual truncation that includes 4 lines beyond the standard "Thread call stack limit is: 1k" line, and 4 truncations on the T7400, one of them of the completely empty variety. I think, though, that I'll wait until I can post this (I'm drafting this during the outage) and hopefully garner some other thoughts on it before continuing. |
jason_gee Send message Joined: 24 Nov 06 Posts: 7489 Credit: 91,093,184 RAC: 0 |
Yes, as we've been discussing in the background, there are two sides to every interface. They're trialling a 5 second wait on the write locks in the client, which is hoped would be enough to cover any app slowness there. Personally I don't consider it more of a workaround than the commit mode builds are for the app side of the two sided interface (every interface having two sides). Fingers crossed it's enough duct tape to cover the hole. I would have liked to see a rigorous treatment of both sides of the exchange to make everything tougher, but then I've got enough of my own shortcuts to harden before I go pointing the bone at sloppy workmanship :) "Living by the wisdom of computer science doesn't sound so bad after all. And unlike most advice, it's backed up by proofs." -- Algorithms to live by: The computer science of human decisions. |
©2024 University of California
SETI@home and Astropulse are funded by grants from the National Science Foundation, NASA, and donations from SETI@home volunteers. AstroPulse is funded in part by the NSF through grant AST-0307956.