Is there a WINAPI command that I can INVOKE to determine if Windows
is in shutdown mode? IBM M/F has a simple way to determine this.
It appears that Windows Task Scheduler will start a task even during
shutdown, which seems weird. I found many Google hits about people
wanting to use WTS to DO a shutdown, but I want to NOT start a task
during shutdown. I didn't see any options in Triggers or Conditions.
In my case, it apparently was killed shortly after, and did not drive
my SetConsoleCtrlHandler code immediately after its' startup, and thus,
not do my cleanup for the next startup. Yet my separate cleanup task
itself, which sleeps forever until the handler is driven, was driven
properly, but BEFORE the new task was started (in fact, the new task
was started 6 seconds after the cleanup task finished, per History
and since I timestamp all my msgs), so it found nothing to clean up.
In a .BAT, I found these:
tasklist.exe /V /FI "IMAGENAME eq SHUTDOWN.exe" | %SystemRoot%\System32\find /i "SHUTDOWN.exe"
wmic.exe os get status /value | %SystemRoot%\System32\find /i "Status=OK"
The first one doesn't find anything at shutdown; perhaps this .exe I'm
looking for isn't there, or perhaps only for a short time, if at all.
It works fine manually, looking for an .exe that I know is running
(ie: my cleanup task).
The second one does work, but I consider it hokey to rely on parsed
data. Is this the same on Win6, 7 and 8? What if it's changed on a whim?
OS and COMPUTERSYSTEM, looking at what seems to be the same thing, produces
different output. WMIC also doesn't seem to set an ERRORLEVEL, at least
from what I can tell.
Also, BOTH seem to require ADMIN authority. They both fail under the
GUEST logonid. Just like FSUTIL, yet my MASM can find volumes w/o being ADMIN.
I'd like to do the latter via a WINAPI, w/o being ADMIN, but I can't seem to
find anything. Any suggestions?
the operating system sends notification messages to all top-level windows
http://masm32.com/board/index.php?topic=1491.msg15340#msg15340 (http://masm32.com/board/index.php?topic=1491.msg15340#msg15340)
you are primarily interested in the second half of that post
for console apps, you want a control handler
this may be more what you want...
INVOKE GetSystemMetrics,SM_SHUTTINGDOWN
;returns EAX <> 0 if shutting down
I posted this on a windows batch file newsgroup.
Hope it helps.
Andy
On Fri, 1 Nov 2013 09:14:18 -0700 (PDT), Andy wrote:
> Is there a WINAPI command that I can INVOKE to determine if Windows
> is in shutdown mode? IBM M/F has a simple way to determine this.
The system doesn't provide shutdown status or log-off status that can be
checked on demand.
> tasklist.exe /V /FI "IMAGENAME eq SHUTDOWN.exe" | %SystemRoot%\System32\find /i "SHUTDOWN.exe"
This only work if the shutdown/logoff was initiated by the SHUTDOWN.EXE.
> wmic.exe os get status /value | %SystemRoot%\System32\find /i "Status=OK"
This will never work. The "Status" property doesn't even provide the
required information. Check MSDN. Don't assume.
> Also, BOTH seem to require ADMIN authority. They both fail under the
> GUEST logonid. Just like FSUTIL, yet my MASM can find volumes w/o being ADMIN.
Accessing WMI and finding volumes are two different things.
> I'd like to do the latter via a WINAPI, w/o being ADMIN, but I can't seem to
> find anything. Any suggestions?
Write an EXE program that has a hidden window.
Handle the shutdown/logoff window message and create a file named
"ShuttingDown.txt" somewhere, then allow shutdown/logoff to proceed.
Make the program run on system startup and does nothing but wait or the
shutdown/logoff window message.
When run, delete the "ShuttingDown.txt" file, if present.
That file will serve as a marker that your batch file can check.
Or you can use the registry instead of a file.
Thank you all for your comments/suggestions, and especially for GetSystemMetrics. This works great, but not EVERY time. Specifically, tasks that are started by WTS after shutdown has started do NOT change this, nor get its' Handler driven, at least in the beginning (in a test of 3 progs in a .BAT, only the 3rd detected shutdown).
My point about VOLUMES was that I can get VOLUMENAMEs w/MASM without being ADMIN. Other than FSUTIL (ADMIN), I don't know how to get this information.
The WMIC does seem to work; if not =OK, I assume a shutdown. I didn't have any ENQ hangs using this, tho perhaps I didn't hit the timing correctly.
I DO have an invisible window, started by WTS as SILENT. However, it gets driven
BEFORE WTS starts the task, and so has nothing to clean up.
Here's my logs so far...it appears that Event13 kills the running .BAT when the
current program finishes (if < SPI_GETWAITTOKILLTIMEOUT) ??? This is the real
problem. Why does WTS start my task if the OS will just flush it and not give it
any time to run?????!!!!!
-----
LT2B, 11/4/13, 19:39:23-44, ENQDEQ.log NOT CLEARED????????????????????????
temp cmt'd 2 DELs in DSNTODAY.bat for 2 ENQDEQ (DSNTODAYAbended...) calls
NOTIFY.txt
SLEEP Mon 11/04/2013 19:39:24.19 error 1073807364; 40010004h WaitToKill expired at shut? DWM EV9009?
even if ran, way B 4 WTS start (right when PowerOff button pressed)
CLEANUP.txt
SLEEP ABENDED!6#u# 2013/11/04 19:39:41.838 0000554131 c:\DAD\SCHEDUL\execs\ c:\DAD\SCHEDUL\execs
ABENDXIT/Handler (6): 3sec B 4 WTS start; ENQDEQ.log empty (u), other 2 erased (#)
ENQDEQWasNOTClearedMon.1104201319462645.log WTOD=19:39:44.693 (matches z102) (prog1)
ED 2013/11/04 19:39:44.178 (matches z969; TOD when written)
WTS start AFTER shutdown!
ENQ request by DSNTODAY
no shutdown detected, no ABENDXIT;
this logic worked on LT1B:
ENQDEQ ABENDED!s?h? 2013/11/04 19:39:13.291 0000000000 c:\DAD\SCHEDUL\execs
GetSystemMetrics detected (s): ENQ request(E), so NOT erased since don't own (h)
ENQDEQE ABENDED!z*** 2013/11/04 19:39:13.291 0000000000 c:\DAD\SCHEDUL\execs
ABENDXIT/GetSystemMetrics detection sets ERRORLEVEL=10000 (*** means # > 999)
.BATs check this in order to exit
DSNTODAYAbendedMon.1104201319394413.log (prog1)
ENQDEQE ABENDED!z969 2013/11/04 19:39:44.178 0000000000 c:\DAD\SCHEDUL\execs
written at start of program
ENQDEQE ABENDED!z102 2013/11/04 19:39:44.693 0000000515 c:\DAD\SCHEDUL\execs
written at end of program; ERRORLEVEL=102 (ENQ successful)
DEQ (prog3) not run? S/B appended?! No z969 so NOT run? No shutdown detected, no ABENDXIT.
Killed? Was running 3.7sec, < SystemParametersInfo/SPI_GETWAITTOKILLTIMEOUT=5sec
EV13: The operating system is shutting down at system time 2013-11-05T01:39:47.626417500Z
this is within prog2
was the .BAT flushed?
DSNTODAY.txt (prog2)
DSNTODAY ABENDED!z969 2013/11/04 19:39:44.709 0000000000 c:\DAD\SCHEDUL\execs
written at start of program
DSNTODAY ABENDED!z000 2013/11/04 19:39:47.844 0000003136 c:\DAD\SCHEDUL\execs
written at end of program; ERRORLEVEL=0
no shutdown detected, no ABENDXIT.
in other tests, prog1 runs, but this does NOT (no Z969 msg, so not run)
EV13: The operating system is shutting down at system time 2013-11-05T02:34:44.405299400Z
this is within prog1
ENQDEQE ABENDED!z969 2013/11/04 20:34:44.186 0000000000 c:\DAD\SCHEDUL\execs
ENQDEQE ABENDED!z102 2013/11/04 20:34:44.467 0000000281 c:\DAD\SCHEDUL\execs
ENQDEQ.txt
ENQDEQ Mon 11/04/2013 19:46:26.41 ### W A R N I N G ###: ENQDEQ: ENQUEUE timed out; ENQUEUE R=ENQDEQ forced! DSN rename w/TOD sfx attempted!
So it appears that when EV13 occurs, the next program in the .BAT is FLUSHED???!!!!!
what is the task ?
if it's brief, you could possibly delay shutdown
Hi *.*:
It's a mute point. If is is in shut down mode or attempting to
shut the station down. The program you are trying to run had better
be real short and fast. The RAM will die when the power goes off
unless you got a UPS. Uninteruptable Power System, and or a nice
GENERAC Diesel Generator. You need a Nice big Battery because the
diesel takes two minutes to get up to speed. Make sure Diesel has a nice
big tank. It will be real fun to debug with no power.
It seems like one should finish everything and then do a shutdown.
I don't much care for diesels because they contribute to noise pollution. :biggrin:
Andy
More testing...
1. I changed my CLEANUP (invisible "sleep forever" window) to make 3 attempts to erase, instead of just 1 after the initial wait:
. #1 done when GetSystemMetrics detected or Handler driven
. #2 waits for the time specified in SPI_GETWAITTOKILLTIMEOUT - 3 seconds (apx)
and then attempts to erase
. #2 waits 15 more seconds (apx; poor SLEEP resolution) and then attempts to erase.
It all works properly using Ctrl-C in a normal DOS window:
C:\DAD\MASM3211>SLEEP.exe +
ABENDXIT 2013/11/08 12:18:42.463
SLEEPk ABENDED!0??? 2013/11/08 12:18:42.463 0000018001 = new WAITTOKILLTIMEOUT (18sec)
SLEEP ABENDED!0uuu 2013/11/08 12:18:42.479 0000082244 #1 (& #ticks since task start)
SLEEP ABENDED!0uuu 2013/11/08 12:18:56.534 0000096315 #2
SLEEP ABENDED!0uuu 2013/11/08 12:19:10.590 0000110371 #3
However, w/WTS non-SILENT, X'ing the window, it fails to do #2 in CLEANUP:
ABENDXIT 2013/11/08 11:19:00.662
SLEEPk ABENDED!2??? 2013/11/08 11:19:00.662 0000018001 = new WAITTOKILLTIMEOUT via GET
SLEEP ABENDED!2uuu 2013/11/08 11:19:00.662 0000010265
LAST RECORD!!!
I DUP'd this in a .log as, it seems, if killed, STDOUT re-dir data is lost?
Per PROCMON, after 4sec, it just gets killed, apparently:
SLEEP.exe 5500 3180 Thread Exit SUCCESS Thread ID: 3180, User Time: 0.0000000, Kernel Time: 0.0312002 0.0000000 11:19:05.6682503 AM
7 SLEEP.exe mainCRTStartup + 0x1eaf, SLEEP.ASM(2215) 0x402eaf
0000002215 SLEEP1SECF SLEEPINVM in ABENDOUT (main thread; must wait for Handler for good RC)
SLEEP.exe 5500 5484 Thread Exit SUCCESS Thread ID: 5484, User Time: 0.0000000, Kernel Time: 0.0156001 0.0000000 11:19:05.6682677 AM
7 SLEEP.exe mainCRTStartup + 0x3a42, SLEEP.ASM(2460) 0x404a42
0000002459 ;* many times, this is as far as it gets???
0000002460 SLEEP1SECF SLEEPINVC2 (handler thread)
SLEEP.exe 5500 5484 Process Exit SUCCESS Exit Status: -1073741510, User Time: 0.0000000 seconds, Kernel Time: 0.0468003 seconds, 0.0000000 11:19:05.6707338 AM
Both of my threads are "sleeping" (waiting for the time to expire, to test this apparent kill).
2. Not sure what u mean by shutdown delay. If you are thinking of the pop-up, in
HKLM\SOFTWARE\Microsoft\Windows NT\CurrentVersion\Windows\ShutdownWarningDialogTimeout,
if this just controls how long the pop-up stays, and then initiates shutdown, this won't help. If I change it from all F's to 10000, all I'd have to do is hit PowerOff 10 seconds earlier, and the result s/b the same as what I've been testing. In any case, doing this produced no pop-up via the PowerOff button (I have it set to shut down) or the Start button, which doesn't even have a confirmation ("Are you sure?") ?!
3. I tried to stop the presumed killing by reading my threads' ACL. It shows
THREAD_TERMINATE as 0. This is a copy, so OR'ing a 1 did nothing. I looked at
SetSecurityInfo, but there doesn't seem to be a way to replace the minimum ACL
(no SID, no D/SACL) itself.
4. I do GETWAITTOKILLTIMEOUT; it is currently 5000. I changed it to 18000 via
SETWAITTOKILLTIMEOUT, and although it displays the value, it isn't honored.
I then added this REG_SZ to \CP\Desktop (HKCU for a DOS normal window, HKU\.default for CLEANUP (for whatever reason)) so did NOT use SETWAITTOKILLTIMEOUT; again, it shows the new value, but it doesn't honor it. This is proven because my 2nd attempt, which now waits 15 seconds, never occurs. Further, EventID102, which says when WTS finishes the CLEANUP task, never occurs (for shutdown), presumably due to the task being killed?
So all this generates these questions:
1. Is there anything in EventLog that I can turn on to prove that my task is being killed? All my evidence sure points to this being the case. Using PROCMON during my testing shows no events after I kill it w/PROCEXPL; just ThreadExit rc=1. Not even WTS Event201, tho the rc=1 IS logged in History? If MS touts this as "dangerous", shouldn't there be a log of the event????!!!! PROCMON shows events in yellow during non-shutdown.
2. Why can't I tell WTS to NOT start a task during shutdown? Why bother if I can't
change the 5sec limit? And if it's SO IMPORTANT to be short, why allow it???
3. What allows WAITTOKILLTIMEOUT to be honored? Why have an SPI if it doesn't work? If it was privileged, why do I see it via the GET when I change it via SET? And I see it from the Registry w/o SET.
4. How can I null the THREAD_TERMINATE access right so a kill will NOT work?
Any 1 of the last 3 would solve my problem...
what task are you trying to perform at shutdown ?
I'm trying NOT to perform tasks at shutdown.
Basically batch jobs.
They run from 2 (when buffered) to 100 (after startup) seconds.
Am I understanding this right? There is NO CONFIRMATION on the shutdown button of the Start menu???!!! NO CONFIRMATION??? I can see it for the PowerOff button; after all, it's on the machine. I switch btx my ADMIN and GUEST a lot, and it's way too easy to hit it by accident! I guess I'll go back to using the old Ctl-Alt-Del, JUST TO AVOID THE SHUTDOWN, since it's not a choice, and is tucked in the
lower-right as RED.
This might provide a partial solution:
http://technet.microsoft.com/en-us/library/cc732119.aspx
Unfortunately, it's not found. I found it in winsxs and copied it to \System32,
but it says the snap plug-in failed.
This also doesn't work:
HKEY_LOCAL_MACHINE\Software\Microsoft\Windows\CurrentVersion\Reliability
New ? DWORD 32
Enter as name: ShutdownReasonUI
Enter as value: 1
there is another method that may help
but, first, i would like to know what the task is that you are trying to perform
in this case, that means i want to know what task you are trying to prevent
you have not explained your goal
Quote from: MtheK on November 09, 2013, 11:10:09 PM
...
Am I understanding this right? There is NO CONFIRMATION on the shutdown button of the Start menu???!!! NO CONFIRMATION??? I can see it for the PowerOff button; after all, it's on the machine. I switch btx my ADMIN and GUEST a lot, and it's way too easy to hit it by accident! I guess I'll go back to using the old Ctl-Alt-Del, JUST TO AVOID THE SHUTDOWN, since it's not a choice, and is tucked in the
lower-right as RED.
You may try to Remove Shutdown button from Taskbar via GPO on Windows 7 Workstations (http://social.technet.microsoft.com/Forums/windowsserver/en-US/020d177b-2841-46d2-9a24-82b8253e93f5/remove-shutdown-button-from-taskbar-via-gpo-on-windows-7-workstations?forum=winserverGP)
Notice that this setting also removes Power Button from Windows Security Screen accessed by pressing CTRL-ALT-DELETE
Alas, I can't find GPMC.MSC either.
As I said, my goal is to NOT start my background tasks at shut down.
I don't understand your question...
Quote from: MtheK on November 10, 2013, 11:26:52 PM
Alas, I can't find GPMC.MSC either.
...
WIN-R , type in "mmc" and run it , answer "Yes" to UAC
... and when mmc window appears ...
File -> Add / Remove Snap-in... -> in the list of available snap-ins find and select Group Policy Object Editor -> press "Add >" Button -> press OK
Expand User Configuration -> expand Administrative Templates -> select Start Menu and Taskbar ...
if you're lucky you'll see something like the screenshot above ;)
Quote from: MtheK on November 10, 2013, 11:26:52 PM
As I said, my goal is to NOT start my background tasks at shut down.
I don't understand your question...
the question is...
what are the "background tasks" ?????
Quote from: dedndave on November 11, 2013, 01:55:29 AM
Quote from: MtheK on November 10, 2013, 11:26:52 PM
As I said, my goal is to NOT start my background tasks at shut down.
I don't understand your question...
the question is...
what are the "background tasks" ?????
Must be Top Secret. :t
Andy
Hardly; it's the DSNTODAY system as described in my very first post:
http://masm32.com/board/index.php?topic=2117.0
ok....
you might try adding a script to the group policy
this allows you to run scripts when the computer shuts down
now - i know that is the opposite of what you want - lol
but, you might be able to use a script to "set a flag", so to speak
for example, your script might run an EXE that creates a mutex handle
then, your scheduled task can try to create the same mutex
if it fails, it means the script EXE is running
First, let me say that this ERRORLEVEL 1073807364 / 40010004h at shutdown was the problem almost every time, causing me to NOT be able to clean up my files. An un-filtered PROCMON capture at shutdown clearly shows some LOUSY PIECE OF GARBAGE apparently going thru the active task chain, and WITHOUT ANY NOTIFICATION, killing most everything it finds within 1 second(!) of pressing the PowerOff button which, in my case, has 'shut down' associated with it. Tho apparently not visible here, its' results sure are: most every process forcibly
ends w/this nasty, DATA-INTEGRITY-PRONE, "DANGEROUS" (ie: MS WINAPI words) rc.
Every "solution" I found on the 'net failed to solve this problem. The closest I can
come to is ADDING 'AutoEndTasks=1' and 'WaitToKillAppTimeout=5000' which, in my case, since I have a 17-second .wav played at shut down, abruptly stops playing it. But that (as well as ADDING 'AutoEndTasks=0') does NOTHING to stop these massive PowerOff forced killings.
Ironically, the only way I can get my program spared is via the 'sleep forever' task. When started by WTS, and ONLY when 'run whether logged on or not' is used, via my logs (since video and audio are suppressed; not good for an external monitor needing those cues) I can see that it is allowed to detect SM_SHUTTINGDOWN, eventually gets its' handler (ABENDXIT) driven, and, ONLY THEN, is finally (probably) killed: at detection, it goes into a different 1-second loop where it OPEN/WRITE/CLOSEs a message file for up to 60 seconds. It never gets to the end, but it IS given time, unlike the forced demise of most all the others immediately after PowerOff?
Here's a chrono collage of the most important info I've collected, in case anyone else has suggestions about this BS DATA INTEGRITY problem:
PROCMON:
wininit.exe 748 772 Thread Create SUCCESS Thread ID: 5424 0.0000000 wininit.exe 616 61130 2:24:40.8321629 PM
PowerOff button pressed
winlogon.exe 1264 664 Process Create SUCCESS C:\windows\system32\LogonUI.exe PID: 3740, Command line: "LogonUI.exe" /flags:0x0 0.0000000 winlogon.exe 740 61169 2:24:40.8363301 PM
System 4 5000 IRP_MJ_WRITE SUCCESS C:\Windows\System32\wdi\LogFiles\ShutdownCKCL.etl Offset: 327,680, Length: 65,536, I/O Flags: Non-cached, Priority: Normal 0.0007953 0 63949 2:24:40.9601158 PM
0005DF50 E9030000534C4545502E657865006300 ....SLEEP.exe.c.
0005E0B0 4500450050002E006500780065000000 E.E.P...e.x.e...
0005FFF0 FFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF ................
. NOTIFY (external monitor via STARTUP):
SLEEP.exe 4720 4672 Thread Exit SUCCESS Thread ID: 4672, User Time: 0.0000000, Kernel Time: 0.0156001 0.0000000 SLEEP.exe 60 3856 113 2:24:41.2926939 PM
SLEEP.exe 4720 4672 Process Exit SUCCESS Exit Status: 1073807364, User Time: 0.0000000 seconds, Kernel Time: 0.0156001 seconds, Private Bytes: 462,848, Peak Private Bytes: 487,424, Working Set: 1,769,472, Peak Working Set: 1,769,472 0.0000000 SLEEP.exe 60 3856 114 2:24:41.3034535 PM
. separate LAN monitor via STARTUP (USUALLY? gets 1073807364):
SLEEP.exe 4828 5572 Thread Exit SUCCESS Thread ID: 5572, User Time: 0.0000000, Kernel Time: 0.0156001 0.0000000 SLEEP.exe 59 3696 111 2:24:41.2734638 PM
SLEEP.exe 4828 5572 Process Exit SUCCESS Exit Status: 10000, User Time: 0.0000000 seconds, Kernel Time: 0.0156001 seconds, Private Bytes: 462,848, Peak Private Bytes: 487,424, Working Set: 1,794,048, Peak Working Set: 1,794,048 0.0000000 SLEEP.exe 59 3696 112 2:24:41.2745509 PM
. separate LAN monitor via WTS (always NEVER gets 1073807364):
SLEEP.exe 2800 1504 Thread Exit SUCCESS Thread ID: 1504, User Time: 0.0156001, Kernel Time: 0.0000000 0.0000000 SLEEP.exe 61 3016 131 2:24:41.3659776 PM
SLEEP.exe 2800 1504 Process Exit SUCCESS Exit Status: 10000, User Time: 0.0156001 seconds, Kernel Time: 0.0000000 seconds, Private Bytes: 466,944, Peak Private Bytes: 466,944, Working Set: 1,785,856, Peak Working Set: 1,785,856 0.0000000 SLEEP.exe 61 3016 132 2:24:41.3722959 PM
. NOTIFY:
LINK.exe 3828 3832 Thread Exit SUCCESS Thread ID: 3832, User Time: 0.0156001, Kernel Time: 0.0000000 0.0000000 ""LINK.exe R=2 3676 172 2:24:41.5319036 PM
LINK.exe 3828 3832 Process Exit SUCCESS Exit Status: 1073807364, User Time: 0.0156001 seconds, Kernel Time: 0.0000000 seconds, Private Bytes: 532,480, Peak Private Bytes: 557,056, Working Set: 1,896,448, Peak Working Set: 1,904,640 0.0000000 ""LINK.exe R=2 3676 173 2:24:41.5331969 PM
. last entry B 4 PROCMON killed?
System 4 96 IRP_MJ_WRITE SUCCESS C:\DAD\prcsmon\ProcessMonitor.PML Offset: 20,971,520, Length: 2,097,152, I/O Flags: Non-cached, Paging I/O, Priority: Normal 0.0216905 0 80739 2:24:41.6662239 PM
NOTIFY/SLEEPX.txt:
SHUTDOWNw0000004720 0000004672 2013/12/23 14:24:41.261 C:\DAD\SCHEDUL\execs
SLEEP Mon 12/23/2013 14:24:41.30 error 1073807364; 40010004h WaitToKill expired at shut? DWM EV9009?
NOTIFYL/X.txt:
NOTIFY2 Mon 12/23/2013 14:24:41.43 error 1073807364; 40010004h WaitToKill expired at shut? DWM EV9009?
SHUTDOWNv0000003828 0000003832 2013/12/23 14:24:41.292 ""LINK.exe R=2 C:\DAD\SCHEDUL\execs
OPENWAITX.txt (separate LAN monitor via STARTUP):
SHUTDOWNv0000004828 0000005572 2013/12/23 14:24:41.261 C:\DAD\TOOLS\MYPROGS\OPENWAIT\V1R2M1
SLEEP ABENDED!sooo 2013/12/23 14:24:41.261 0000021996
SLEEP Mon 12/23/2013 14:24:41.51 TERMINATED by Ctl-C! / 10000
OPENWAITX.txt (DUP separate LAN monitor via WTS):
SHUTDOWNz0000002800 0000001504 2013/12/23 14:24:41.292 c:\DAD\SCHEDUL\OPENWAIT\V1R2M1
SLEEP ABENDED!3ooo 2013/12/23 14:24:41.339 0000022074
SLEEP Mon 12/23/2013 14:24:41.40 TERMINATED by Ctl-C! / 10000
SLEEP.log (NOTIFY/SLEEP; 'sleep forever' task via WTS):
SHUTDOWNw0000004720 0000004672 2013/12/23 14:24:41.261 C:\DAD\SCHEDUL\execs
SHUTDOWNz0000002200 0000002204 2013/12/23 14:24:41.339 c:\DAD\SCHEDUL\execs
...
ABENDXITv0000002200 0000002204 2013/12/23 14:24:58.773 c:\DAD\SCHEDUL\execs
...
last record written:
SLEEP ABENDED!huuu 2013/12/23 14:25:02.158 0002015377 c:\DAD\SCHEDUL\execs\
LINKJ.log (NOTIFY; DSNTODAY via WTS):
SHUTDOWNv0000003828 0000003832 2013/12/23 14:24:41.292 ""LINK.exe R=2 C:\DAD\SCHEDUL\execs
... (and LINKWTS *AB.txt; DSNTODAY via WTS started AFTER shutdown; after last PROCMON entry):
SHUTDOWNz0000002768 0000005464 2013/12/23 14:24:44.059 ""LINK.exe R=1 c:\DAD\SCHEDUL\execs
LINK ABENDED!3??? 2013/12/23 14:24:44.059 0000000000 0000002768 0000005464
...
LINK + ABENDED!z*** 2013/12/23 14:24:44.069 0000000016 0000002768 0000005464 4294967295 0000000000 0000000000 0000000000
LINKX *AB.txt:
LINK Mon 12/23/2013 14:24:44.06 TERMINATED by Ctl-C! / 10000
EventID=13 (OS shutdown):
14:25:01.66
Thankx much for the mutex suggestion. Although it failed the same way, since it only lasts until the process is terminated/killed, I was finally able to turn that POG
dis-advantage into an advantage! Now, my ENQ resource, instead of a file, is a mutex (actually, an Event). Since it can't persist across restarts, now I can't have a hang at startup any more, tho, now, I need a top-level program to hold onto it while my .BATs run.
So, now, I no longer care that:
. this DATA-INTEGRITY-PRONE lack-of-log POG abruptly & immediately kills most all tasks
. it won't honor the WAITTOKILLTIMEOUT setting via the Registry or the SPI
. WTS starts my task after shutdown and then it gets killed shortly after (if shutdown isn't allowed to be detected or if the handler is not driven).
Perhaps it's time for a new OS that doesn't cause customer data integrity issues.
Perhaps Hercules, the s/370 IBM MainFrame emulator on the PC, can hopefully evolve into one.
FYI: capturing the apparent force-killer at PowerOff appears to be in DllHost.exe+12E9:
FAULTING_THREAD: 00000da4
. 0 Id: da0.da4 Suspend: 0 Teb: 7ffdf000 Unfrozen
Priority: 0 Priority class: 32
ChildEBP RetAddr Args to Child
0006f560 77995cac 75d268cc 00000002 0006f5b4 ntdll!KiFastSystemCallRet (FPO: [0,0,0])
...
0006f898 771150bb 0006f8b0 0006f8d0 0006f8b0 ntdll!KiUserExceptionDispatcher+0xf (FPO: [2,0,0]) (CONTEXT @ 0006f8d0)
0006fbb0 009112e9 ffffffff 00000000 00912370 kernel32!TerminateProcessStub (FPO: [Non-Fpo])
009112d8 10 91 00 57 ff 15 04 10 91 00 50 ff 15 00 10 91 00 8b 4d fc
0006fe40 009114b1 00910000 00000000 00091cae dllhost!wWinMain+0xf5 (FPO: [Non-Fpo])
0006fed4 77121114 7ffd4000 0006ff20 779ab429 dllhost!_initterm_e+0x1b1 (FPO: [Non-Fpo])
0006fee0 779ab429 7ffd4000 77a40abb 00000000 kernel32!BaseThreadInitThunk+0xe (FPO: [Non-Fpo])
...
!dlls -v
0x00091e00: C:\windows\system32\DllHost.exe
Base 0x00910000 EntryPoint 0x00911609 Size 0x00005000
Flags 0x00004000 LoadCount 0x0000ffff TlsIndex 0x00000000
LDRP_ENTRY_PROCESSED
Company Name Microsoft Corporation
Product Name Microsoft® Windows® Operating System
Product Version 6.1.7600.16385
Original Filename dllhost.exe
File Description COM Surrogate
File Version 6.1.7600.16385 (win7_rtm.090713-1255)
from DUMPBIN:
77E2509B 4C0 TerminateProcess
I had 7 dumps total, all similar to this first one.
FYI: further tests show DllHost.exe is probably just a valid user of WINAPI TerminateProcess. A PROCMON capture w/my BATs still show this ERRORLEVEL occuring, but w/no zap'd forced faults (via dumps) occuring B 4 PROCMON itself is killed. So this force-killer is probably NOT using the API to kill PIDs unless another API command does so?
FYI: final thoughts
I can now pretty much avoid the force-killer by using the minimum-allowed
INVOKE Sleep interval, tho, if you think that's a 1, it's not, based on
GetTickCount differences. It's apx 15ms, tho it's quite inconsistent.
I've seen wait times over 6 seconds (I log both minimums and maximums).
However, it's usually good enough to mostly avoid being force-killed.
I also found that, if my program is a SERVICE (per TASKLIST), the
force-killer spares it, which then USUALLY gives me enough time to
terminate gracefully. This is accomplished by WTS's use of "run whether
user is logged on or not". Unfortunately, with no video or audio cues,
another normal program, read-only (so no ENQ is held), interfaces w/it,
which can also use the minimum-allowed INVOKE Sleep interval.
Finally, there are still force-killings, even as a SERVICE, tho I
haven't figured out why. For whatever reason, in this instance, the
handler is NOT called, nor is SM_SHUTTINGDOWN set. This is verified
by a 1-second "heartbeat" monitor, which shows the latest values of
the variables I set when either is detected, in a file that I
open/erase/write/close, and only erased w/no data when/if I exit.
This record is saved/logged at restart if this file is not empty.
For sure, since the handler is a separate TID, started only by the OS,
and all it does is set a variable that is checked by the main TID,
during these killings, both variables are 0, meaning no detection
occured within the last second (unless either an inconsistent
interval occured, or my .DATA addr wasn't passed to my handler TID,
which, so far in testing, is ALWAYS passed?).
I also maintain a "killed list" in a similar file; when I start,
I open/write/close an entry, and when I exit, I open/erase/close
the entry. If any entries exist, then I was killed or, for whatever
reason, wasn't allowed to exit (no dumps, so did not crash). So far,
this hasn't occured. I can see the entry when the program is actually
running, and see it gone after it exits, so I know it works.
I also have an ECHO in the WTS .BAT at the end, which is NOT done,
implying the window was killed, since it ALWAYS occurs normally.
If you have a similar problem, hopefully, this info can help.
FYI,
I put together a set of .BATs and an MASM program that scans
ALL Win event logs (including the 400+ Application logs, based
on a 'WEVTUTIL EL' O/P) at once, looking for ANY records that fall
around a specific TOD (TimeOfDay) of an event you are interested in.
I don't know how to do this globally in Event Viewer (if possible?),
just individually. I use WTS to either run it automatically every hour,
or on-demand, for a span of an hour, for the current time.
All reports (.txt) can go to a unique DIR.
For example, if I pressed the Poweroff button at 07:38:00,
perhaps, maybe, this unknown force-killer or the OS would log an
entry for each PID that was force-killed, somewhere. Since MS says
the WINAPI 'TerminateProcess' is "dangerous", one would think it
would be logged by something. But, alas, apparently not:
(look for records btx 07:37:45 and 07:38:15 for today)
APPEVTOD.BAT 073800 15 (run ELEVATED for System,etc logs)
There are ZERO records in the Windows logs (26 of 'em),
and only 1 Application log has 3 records:
APPEVTOT 0,"Microsoft-Windows-TaskScheduler/Operational"
this is \SCHEDUL NOTIFY running SLEEP under WTS as a SERVICE,
thus spared by the force-killer, detecting shutdown
If I expand to 20 seconds, covering my 17sec shutdown .wav,
I then get 55 records in the Windows logs, and many more app logs:
APPEVTOT 0,"Microsoft-Windows-DriverFrameworks-UserMode/Operational"
APPEVTOT 0,"Microsoft-Windows-GroupPolicy/Operational"
APPEVTOT 0,"Microsoft-Windows-International/Operational"
APPEVTOT 0,"Microsoft-Windows-NetworkProfile/Operational"
APPEVTOT 0,"Microsoft-Windows-Resource-Exhaustion-Detector/Operational"
APPEVTOT 0,"Microsoft-Windows-TaskScheduler/Operational"
APPEVTOT 0,"Microsoft-Windows-TerminalServices-LocalSessionManager/Operational"
APPEVTOT 0,"Microsoft-Windows-User Profile Service/Operational"
APPEVTOT 0,"Microsoft-Windows-Windows Defender/WHC"
APPEVTOT 0,"Microsoft-Windows-Windows Firewall With Advanced Security/Firewall"
APPEVTOT 0,"Microsoft-Windows-WindowsUpdateClient/Operational"
Unfortunately, none of any of these reside within 1 sec, when the force-killer
runs; they all begin after the .wav is finished.
Even a manual kill by PROCEXP (Process Explorer ELEVATED) fails to log anything
at the moment of the kill. PROCMON still fails to show anything except all the
PIDs failing w/rc=1073807364; 40010004h at PowerOff. ZERO response from SysInternals for info since JAN.
So, after all this, I can now pretty confidently say that, even tho, per MS quote,
TerminateProcess is "dangerous", there appears to be NO LOGGING whenever a PID is force-killed!!! Unless there is a log that is NOT turned on, and unless this
possible log can be determined and enabled, this pretty much SUCKS THE WAZOO!!!
This is available in the DSNTODAY system. Since TODs are retrieved internally,
this s/b locale (regional) independent. Perhaps someone outside of the USA could
test it; the instructions are in the .BAT, and its' URL is here:
http://users.foxvalley.net/~qcd/index4.htm
Better if someone who uses a locale naturally try it, as opposed to artificially.
Thankx.
Here's an example of something that DOES log something when it kills a task,
so the capability exists. In my case, only part of the .BAT started by WTS ran:
SCHEDUL Thu 08/14/2014 22:45:00.21 calling...
DSNTODAY Thu 08/14/2014 22:45:04.60 32bit Good: DSNTODAY=0,CMSort=0
The mere existance of this log says something failed/killed/etc,
since the DELETE, run near the end, did not erase it.
So, by doing this:
appevtod.bat 224504 6 9 (6 second span, 9 days ago)
explains why it was killed:
Event[9]:
Log Name: Microsoft-Windows-TaskScheduler/Operational
Source: Microsoft-Windows-TaskScheduler
Date: 2014-08-14T22:45:05.659
Task Scheduler stopped instance "{49CADF06-478E-401D-B38A-1FB5F9DEE975}"
of task "\SCHEDUL execs" because the computer is switching to battery power.
In my case, I allow WTS to do this.
You'd think that 'TerminateProcess' would do this too, yet
I've enabled every appl log, even the analytic,etc (in-memory ONLY) logs,
yet there is NOTHING similar to what WTS does. Even killing via PROCEXP
fails to show any records in the analytic,etc logs B 4 re-boot...
I FINALLY figured out how to make this force-killer wait like I
think it should at PowerOff!
Using SM_SHUTTINGDOWN and SetConsoleCtrlHandler, when shutdown is
detected by either, I now write a Windows EventLog record B 4 I exit.
I also have a WTS trigger, based on that Eventlog record, to start a
.BAT which has things like 'tasklist /v', 'pslist -t', etc, run
multiple times in the .BAT, spaced a few seconds apart. Since I set
this to a SERVICE, the force-killer had always spared this, so I was
able to use all this output to detect a pattern to the force-killer.
It appears that it's explorer.exe-related. From the output, at +0s
into it, when I was always a few tenths late, and also at +2s and
+4s, the explorer PID never had any children (sub-PIDs). Most all
normal programs run under the explorer parent.
So I wrote a simple test program to try to make it wait when it was
starting my handler thread. When I SLEEP for 4.836s (just under
the default SPI_GETWAITTOKILLTIMEOUT) in it, I can make it wait, to
give ALL programs under explorer more time to finish, cleanup, etc
than apx 2 tenths of a second!! I just have to have this running B 4
PowerOff. In my case, I have it in \STARTUP. It just sits there all
day, sleeping, waiting for a shutdown detection.
Getting this was VERY FRUSTRATING!!! For some STUPID reason, if
either of these 2 INVOKEs were even COMPILED into my program, let
alone run (I JMP'd around them), the force-killer would NOT honor my
SLEEP (I, and all the others, would get force-killed):
INVOKE SystemParametersInfo,
SPI_GETWAITTOKILLTIMEOUT, ; x'007A'
0,
OFFSET WAITKILL,
0
INVOKE GetSystemMetrics,
SM_SHUTTINGDOWN ; x'2000'
Since all my programs use them to race (and usually win, but not 100%
due to the erratic SLEEP behaviour (I've seen a 15ms request take
over 5s!)) the force-killer, I had to make a new "virgin" program,
TESTFK, to cause it to wait successfully! I can only assume that, for
some reason, when my handler thread is started, it checks the symbols
from my program, and if either of those exist, it basically sets its'
timeout to ZERO, thus foiling my attempt to make it wait! Worse,
during testing of 1 of my external monitor programs w/this code, it
ended up hanging and not exiting. I had tried to only honor the
handler to detect shutdown dynamically, but it turns out that the
handler was NEVER CALLED (PROCMON never showed a 'Thread Create').
Yet my virgin test program worked??!! So, again, it seems that the
mere presense of the above 2 caused my handler to NOT be started!?
Now, my WTS trigger .BAT shows all explorer's children (in this
case, 13 that do NOT exit @ PowerOff (mine have already exited))
at +0s into the .BAT. At +2s, all are still there! At +4s (apx 7s
total), only explorer (the parent) exists. This jives w/my SLEEP:
@@@@@ SCHEDUL Sun 10/05/2014 5:32:57.74 starting...
##### SCHEDUL Sun 10/05/2014 5:32:58.07 ended; step 2A...
...
explorer 3044 8 31 867 248224 53084 38844
...
cmd 3576 8 1 24 33652 2616 1828
TESTFK 3708 8 1 5 6212 956 148
$$$$$ SCHEDUL Sun 10/05/2014 5:32:58.20 ended; step 2B...
...
explorer 3044 8 31 867 248224 53084 38844
...
cmd 3576 8 1 24 33652 2616 1828
TESTFK 3708 8 1 5 6212 956 148
+++++ SCHEDUL Sun 10/05/2014 5:33:00.24 ended; step 4C...
...
explorer 3044 8 28 683 239572 55812 38808
***** SCHEDUL Sun 10/05/2014 5:33:04.23 ended.
So at least now my programs get a decent time to do cleanup,
at least under Win7. I no longer (but still do anyway) must do:
. SetPriorityClass/REALTIME_PRIORITY_CLASS (which actually only gives
me HIGH_PRIORITY_CLASS)
. SetProcessShutdownParameters (do me last)
. minimum SLEEP interval (15ms; it basically, but not exactly, is a
x'0F' multiple, meaning if u ask for 1ms, u get 15; ask for 16, u
get 31; ask for 32, u get 47, etc, as verified by GetTickCount diffs).
So if u have a similar problem, try starting TESTFK B 4 PowerOff
and see if your program(s) then get a decent amount of time to do
cleanup.
Hi MtheK:
Get a UPS Un intruptible Power Supply. It can be a Large Battey with
a nice Diesel. No worries.
Very handy in Hotel{s] in Antigua and Radar sites and BlackBerry.
Regards: herge
Here are my latest test results (see below).
To sum up, a SetConsoleCtrlHandler will NOT(!) be driven during SHUTDOWN (PowerOff) if SM_SHUTTINGDOWN was used (coded or dynamically) in a TCB(*) that remains active, which makes it prey to the .2s force-killer!!! However, it WILL(!) be driven, even if SM was used, when X'ing the window (NOT PowerOff). Why the distinction?
Perhaps the best use of this program is when you are using PROCMON to debug SHUTDOWN problems. This gains apx 5s w/each active window B 4 shutdown, up to a probable maximum (tested 3 for apx 15s total gain, and also tested up to 7 where the "program close" dark shutdown screen counts down; both were synchronous as observed/logged (a LIFO queue?)).
(*) TCB is mainframe-speak for application startup(main) thread (from .exe).
(*) S/T is "subtask" for a different thread (from CreateThread).
these 7 trio runs are via \MASM3211 .zip, NOT ELEVATED, SLEEPSEC (used in wait loop) @ 15ms...
(TESTFK.log) TICKDIFF PID TID PPID RETVALUE ERRORRC DLHANDLE3A APIADDR3A APIADDR3C SETABEND THREADBGN THREADFIN GETPROCP GETPROCN SHUTCLmTCB ABENDWB6 ABENDWB5 ABENDWB4 ABENDWB3 ABNDNWSYNC ABENDFIN ABENDWB
run#1; TESTFK.bat w/hard=null (dft) then X window (no waiting, no .BAT ECHO in TESTFKX.txt (LOST DATA)).
2014/10/24 18:05:20.183 0000005835 0000002132 0000002684 0000002448 0000000107 0000000002 1966669824 1966769161 1885867114 0000000001 0000000001 0000000001 0000000032 0000000128 0000000000 4294966696 4294966796 0000000000 0000000002 0000000001 0000000001 0000000000
2014/10/24 18:05:21.805 0000010109 0000005712 0000002192 0000004408 0000000107 0000000002 1966669824 1966769161 1885867114 0000000001 0000000001 0000000001 0000000032 0000000128 0000000000 4294966696 4294966796 0000000000 0000000002 0000000001 0000000001 0000000000
2014/10/24 18:05:23.708 0000014960 0000004860 0000004500 0000001248 0000000107 0000000002 1966669824 1966769161 1885867114 0000000001 0000000001 0000000001 0000000032 0000000128 0000000000 4294966696 4294966796 0000000000 0000000002 0000000001 0000000001 0000000000
only 1 msg since ABENDFIN=1 (SetConsoleCtrlHandler/ABENDXIT) WAS run,
EVEN THO the S/T already did a SM_SHUTTINGDOWN call (TFIN=1; rc=113 occurs if not done),
meaning this SM call appears to be TCB-related.
run#2; TESTFK.bat w/hard=? then X window (no waiting, no .BAT ECHO in TESTFKX.txt (LOST DATA)).
2014/10/24 18:07:20.921?0000017036 0000003872 0000001424 0000002124 0000000107 0000000002 1966669824 1966769161 1885867114 0000000001 0000000001 0000000001 0000000032 0000000128 0000000001 4294966696 0000000000 0000000000 0000000002 0000000001 0000000001 0000000000
2014/10/24 18:07:25.616?0000024835 0000002144 0000005124 0000002836 0000000107 0000000002 1966669824 1966769161 1885867114 0000000001 0000000001 0000000001 0000000032 0000000128 0000000001 4294966696 0000000000 0000000000 0000000002 0000000001 0000000001 0000000000
2014/10/24 18:07:30.796?0000033602 0000001568 0000002188 0000004996 0000000107 0000000002 1966669824 1966769161 1885867114 0000000001 0000000001 0000000001 0000000032 0000000128 0000000001 4294966696 0000000000 0000000000 0000000002 0000000001 0000000001 0000000000
only 1 msg since ABENDFIN=1. NOTE: ABENDXIT IS(!) called for X window (WB3=2),
with(!) the SM call in main TCB (SHUTCLmTCB)! ABENDWB NOT set at this moment.
run#3; TESTFK.bat w/hard=null and SHUTDOWN (this waits, as designed, in ABENDXIT 4.836s, but no .BAT ECHO in TESTFKX.txt (LOST DATA)).
2014/10/24 18:10:10.845 0000012792 0000005272 0000002488 0000005336 0000000107 0000000002 1966669824 1966769161 1885867114 0000000001 0000000001 0000000001 0000000032 0000000128 0000000000 4294966696 4294966796 0000000000 0000000006 0000000001 0000000001 0000000000
2014/10/24 18:10:15.681 0000020608 0000001688 0000000920 0000004148 0000000107 0000000002 1966669824 1966769161 1885867114 0000000001 0000000001 0000000001 0000000032 0000000128 0000000000 4294966696 4294966796 0000000000 0000000006 0000000001 0000000001 0000000000
2014/10/24 18:10:20.798 0000028954 0000002444 0000005392 0000004588 0000000107 0000000002 1966669824 1966769161 1885867114 0000000001 0000000001 0000000001 0000000032 0000000128 0000000000 4294966696 4294966796 0000000000 0000000006 0000000001 0000000001 0000000000
only 1 msg since ABENDXIT WAS(!) called (FIN=1,WB3=6) with NO(!) SM call in main TCB!
So ABENDWB NOT set.
run#4; TESTFK.bat w/hard=? and SHUTDOWN (NOT KILLED)
Got TESTFKX.txt record (done B 4 being killed):
TESTFK Thu 10/23/2014 10:02:09.70 XIT=N, WB=Y, TFIN=Y, APIERR=N / 104
2014/10/23 10:02:09.658?0000014368 0000005556 0000005368 0000003568 0000000104 0000000002 1970012160 1970111497 1885867114 0000000001 0000000001 0000000001 0000000032 0000000128 0000000001 0000000001 0000000001 0000000000 0000000000 0000000000 0000000000 0000000001
2014/10/23 10:02:09.658?0000014368 0000005556 0000005368 0000003568 0000000104 0000000002 1970012160 1970111497 1885867114 0000000001 0000000001 0000000001 0000000032 0000000128 0000000001 0000000001 0000000001 0000000000 0000000000 0000000000 0000000000 0000000001
2 msgs (not trio run); 1 B 4, 1 after SLEEPWAIT, but WASN'T(!) doing it (same TOD);
was cmt'd! So NO WAITING AT ALL! NO LOST DATA (this time)!
run#4a; now WANT to be killed for waiting MORE THAN 2 TENTHS OF A SECOND!!!!!!!!!!!...
Got TESTFKX.txt record (done B 4 being killed, probably due to minimal SLEEPSEC, tho usually do NOT even get this (LOST DATA)):
TESTFK Fri 10/24/2014 18:20:40.93 error 1073807364; 40010004h WaitToKill expired at shut? DWM EV9009?
2014/10/24 18:20:40.839?0000017534 0000006128 0000006132 0000006104 0000000104 0000000002 1988493312 1988592649 1885867114 0000000001 0000000001 0000000001 0000000032 0000000128 0000000001 4294966696 0000000001 0000000000 0000000000 0000000000 0000000000 0000000001
2014/10/24 18:20:40.839?0000022870 0000005980 0000005984 0000005928 0000000104 0000000002 1988493312 1988592649 1885867114 0000000001 0000000001 0000000001 0000000032 0000000128 0000000001 4294966696 0000000001 0000000000 0000000000 0000000000 0000000000 0000000001
2014/10/24 18:20:40.839?0000020264 0000006080 0000006084 0000006056 0000000104 0000000002 1988493312 1988592649 1885867114 0000000001 0000000001 0000000001 0000000032 0000000128 0000000001 4294966696 0000000001 0000000000 0000000000 0000000000 0000000000 0000000001
only first msg, not 2, tho ABNDNWSYNC/FIN/WB3=0, so most likely killed per .BAT ERRORLEVEL. ABENDWB IS(!) set. With(!) SM call in main TCB! With(!) SM call done in now-gone S/T!
run#4b as run#4a (AGAIN) (no .BAT ECHO in TESTFKX.txt (LOST DATA) (this time)).
2014/10/24 18:16:16.799?0000027300 0000001412 0000001444 0000000948 0000000104 0000000002 1992163328 1992262665 1885867114 0000000001 0000000001 0000000001 0000000032 0000000128 0000000001 4294966696 0000000001 0000000000 0000000000 0000000000 0000000000 0000000001
2014/10/24 18:16:16.799?0000018720 0000002312 0000002320 0000002180 0000000104 0000000002 1992163328 1992262665 1885867114 0000000001 0000000001 0000000001 0000000032 0000000128 0000000001 4294966696 0000000001 0000000000 0000000000 0000000000 0000000000 0000000001
2014/10/24 18:16:16.799?0000024679 0000001568 0000002100 0000001980 0000000104 0000000002 1992163328 1992262665 1885867114 0000000001 0000000001 0000000001 0000000032 0000000128 0000000001 4294966696 0000000001 0000000000 0000000000 0000000000 0000000000 0000000001
only first msg (as run#4a), so killed!
run#4c as run#4a (AGAIN) (no .BAT ECHO in TESTFKX.txt (LOST DATA) (this time)).
2014/10/24 18:28:28.808?0000139028 0000000160 0000003704 0000003304 0000000104 0000000002 1989672960 1989772297 1885867114 0000000001 0000000001 0000000001 0000000032 0000000128 0000000001 4294966696 0000000001 0000000000 0000000000 0000000000 0000000000 0000000001
2014/10/24 18:28:28.808?0000142601 0000004888 0000004892 0000002600 0000000104 0000000002 1989672960 1989772297 1885867114 0000000001 0000000001 0000000001 0000000032 0000000128 0000000001 4294966696 0000000001 0000000000 0000000000 0000000000 0000000000 0000000001
2014/10/24 18:28:28.808?0000136204 0000000892 0000000484 0000001708 0000000104 0000000002 1989672960 1989772297 1885867114 0000000001 0000000001 0000000001 0000000032 0000000128 0000000001 4294966696 0000000001 0000000000 0000000000 0000000000 0000000000 0000000001
only first msg (as run#4a), so killed!
per PROCMON which was ONLY(!) kept alive for so "long" @ PowerOff by my other TESTFK.bat (\STARTUP) running hard=null:
wininit.exe 768 788 Thread Create SUCCESS Thread ID: 6096 0.0000000 wininit.exe 640 550 6:28:28.3962968 PM
... (all entries for PID160) ...
... no 'Thread Create' for ABENDXIT after .408s ...detected ABENDWB=1...
prev testing w/o acting on ABENDWB results in being killed and STILL w/no 'Thread Create'
TESTFK.exe 160 3704 IRP_MJ_CREATE SUCCESS C:\DAD\MASM3211\TESTFK.log ...OpenResult: Opened 0.0000540 TESTFK.exe 3304 1109 6:28:28.8042042 PM
TESTFK.exe 160 3704 IRP_MJ_WRITE SUCCESS C:\DAD\MASM3211\TESTFK.log Offset: 4,005, Length: 267, Priority: Normal 0.0002647 TESTFK.exe 3304 1114 6:28:28.8045152 PM
my program's stack
11 TESTFK.exe mainCRTStartup + 0x11fb, TESTFK.ASM(1188) 0x4021fb C:\DAD\MASM3211\TESTFK.exe
0000001188 INVOKE WriteFile,OTHANDLE,
TESTFK.exe 160 3704 IRP_MJ_CLEANUP SUCCESS C:\DAD\MASM3211\TESTFK.log 0.0000822 TESTFK.exe 3304 1117 6:28:28.8047999 PM
14 TESTFK.exe mainCRTStartup + 0x121f, TESTFK.ASM(1204) 0x40221f C:\DAD\MASM3211\TESTFK.exe
0000001204 INVOKE CloseHandle,OTHANDLE
... next s/b in SLEEPWAIT since ABENDFIN=0 ...
... after 0.1921389s ...
TESTFK.exe 160 3704 Thread Exit SUCCESS Thread ID: 3704, User Time: 0.0000000, Kernel Time: 0.0000000 0.0000000 TESTFK.exe 3304 1426 6:28:28.9969388 PM
7 TESTFK.exe mainCRTStartup + 0x1acb, TESTFK.ASM(1292) 0x402acb C:\DAD\MASM3211\TESTFK.exe
0000001292 INVOKE Sleep,SLEEPWAIT <<<===### NOT in ExitThread, so was killed!
TESTFK.exe 160 3704 Process Exit SUCCESS Exit Status: 1073807364, User Time: 0.0000000 seconds, Kernel Time: 0.0000000 seconds...0.0000000 TESTFK.exe 3304 1446 6:28:29.0036065 PM
... (last record) ... after 5.8427865s ...
SynTPHelper.exe 3800 3804 Process Exit SUCCESS Exit Status: 1073807364, User Time: 0.0000000 seconds, Kernel Time: 0.0000000 seconds...0.0000000 "C:\Program Files\..." 3212 8096 6:28:34.2390833 PM
... this, like calc.exe etc, WAS(!) delayed from being killed (as PROCMON was) by \STARTUP TESTFK.bat hard=null.
I've determined what is at least created when the first
SM_SHUTTINGDOWN call is done in the main thread dynamically.
Using WinDbg with PROCessEXPlorer (PROCEXP)/Handle view and:
INVOKE NtQuerySystemInformation,
SystemHandleInformation,...
both before and after the call (in PROCEXP, a new handle is green in
the 1st interval), along with batch PSLISTs,etc, then comparing all
their results, shows that an un-named infinite (Create)Event handle,
protected from close, was added:
d0 0b 00 00 0c 01 2c 00 a8 bc c0 8a 03 00 1f 00
Handle 00000028 = HANDLE_FLAG_PROTECT_FROM_CLOSE
(so can't be closed until thread exit?)
Type Event
Attributes 0
GrantedAccess 0x1f0003:
Delete,ReadControl,WriteDac,WriteOwner,Synch
QueryState,ModifyState
HandleCount 2
PointerCount 4
Name <none>
No object specific information available
Unfortunately, closing that handle, after un-protecting it, makes
no difference. PROCEXP shows it gone (from grey to nothing) and my
before and after handle lists do NOT increase or change (the # of
handles for my PID stay the same, and the # of events stay the same)
after subsequent calls. So a new Event handle is NOT made, even tho
the previous Event handle is now gone. However, the abend handler
(ABENDXIT) is STILL NOT driven at phase 1 PowerOff (before the
shutdown .wav and "program close" dark screen), so something else is
probably set somewhere which the force-killer also uses, probably
first.
This explains why my "subtask" thread CAN do the call and exit, yet
still get ABENDXIT driven for the main thread which does NOT do the
call (to keep PROCessMONitor (PROCMON) alive long enough for me to
trace everything during shutdown).
This is probably part of what the force-killer uses when it decides
to screw you by NOT driving ABENDXIT at phase 1 PowerOff.
I also found 2 more commands that re-acts as SM_SHUTTINGDOWN does:
INVOKE PlaySound
INVOKE MessageBeep
in that, if coded, ABENDXIT will NOT be driven at phase 1 PowerOff!
Finding those took effort: ended up comparing the "imports" with a
program lacking the SM_CALL (wasn't being killed), eliminating the
duplicates, and testing each leftover until ABENDXIT was driven.
No documentation anywhere on what commands to not even code for this?
Another interesting item is that CreateProcess will get an rc19
(ERROR_WRITE_PROTECT) when EventLog13 is written. And why is WTS
starting my task so near powering off and not driving ABENDXIT?
When NOT doing the call in the main thread, to get ABENDXIT driven,
the time given does not appear to be alterable. I tried adding these
registry entries with changed values and re-booted:
HKEY_CURRENT_USER\Control Panel\Desktop
PowerOffTimeout
WaitToKillAppTimeout
WaitToKillTimeout (default 5000ms)
WaitToKillServiceTimeout
(NOT changed, since already at 12000ms and not a factor at phase
1 PowerOff since TESTFK.exe gets killed if it waits more than 5
seconds with -1073741510/C000013Ah)
HungAppTimeout (default 5000ms)
when I then can see them changed (2 of the last 3 set to 10000 and
15000ms respectively) in my "subtask" thread using:
INVOKE SystemParametersInfo,SPI_GET...
dynamically, but all to no avail as the OS still gives 5 seconds.
I ended up removing the SM_CALL from all my productional programs.
I kept 1 test program using it, mainly for point-of-reference. It
also is "read-only" in that it has no cleanup to do, outside of the
lost .BAT ECHO and occasionally even my own program, which is still
annoying. I appropriately renamed it to "SCREWJOB", and all it does
is capture all lost "heartbeats" which says when (apx1s) it was last
OK. The results are "very interesting":
. kicked up SLEEP interval to 499ms
. at first PowerOn of NEW day, them immediate PowerOff, it usually
does NOT get killed; this day "span" may be just over an hour?
. subsequent PowerOn/PowerOffs in the same "span" are mostly killed
. manually X'ing the window and re-starting sometimes is NOT killed
It appears that a dynamic timeout for a certain span is being used?
So, in summary, if you need to do cleanup at phase 1 PowerOff, you
can pick your poison:
. if you want 100% (so far since the change) assurance that you won't
be killed by the force-killer, use SetConsoleCtrlHandler ONLY, which
gives at least 5 seconds (un-alterable?).
However, since, once that thread exits, the main thread (if still
active) and its' parent is killed within 2 THOUSANDths of a second,
if you are expecting an ECHO from the parent (ie: cmd.exe which runs
the .BAT), DON'T COUNT ON IT!!! Most of the time, nothing occurs! If
you're lucky, you may get the ERRORLEVEL 1073807364/40010004h. This
means that ALL info you want to collect MUST be done by YOUR
programs' ABENDXIT; at least you are given a decent amount of time
for this. In retrospect, this answers the original question of why I
was getting killed. As long as I ensure the handler thread exits
LAST, all is OK. Also, the handler thread can independently capture
fields in the main thread, as for debugging.
The ERRORLEVEL that is passed (when the ECHO DOES work) is from the
LAST thread that exits, so sync'ing up w/the main thread may be
necessary.
Making your program a WTS SERVICE, even with the imbedded SM_CALL,
will also seemingly spare you from the phase 1 force-killer.
. if you want the .BAT ECHO as well, then using the SM_CALL, with the
proper pre-setup beforehand, lets you race the force-killer, and, in
my case, usually win, say, 9 out of 10 times w/a quick SLEEP interval.
However, you DO risk getting killed, either your program, and/or
your parent. You risk losing data integrity (LOST DATA) if ANY(!)
"long" (apx 2 TENTHs of a second!) wait occurs, perhaps due to:
1. erratic 'INVOKE Sleep' results (if using this B 4 the PowerOff)
2. hang in DeregisterEventSource
this was moved to a separate "subtask" thread so that, if
killed, oh well, except that it still prevents the PID from
exiting which prevents the parent from running. Fortunately, if
it was just not done, to let the OS do it, then there is no
hang, and the PID exits normally?!
3. who knows what else (that 10%)!!!
Merely running PROCMON seems to extend this "long" wait briefly,
which, ALSO, does NOT appear to be alterable (haven't found a
registry entry for this "WAITTOKILL" time that works, especially now
that I have the proof by being able to keep PROCMON alive?).
Too bad the OS, which considers killing "dangerous", doesn't seem
to log its' own killings for data integrity purposes! IBM mainframe
always has, even at the expense of delays. Perhaps that says it all.
I believe I may have found a way to help identify if a program is
vulnerable to the PowerOff force-killer or not (at least in my case).
If your .exe (specifically, your .map) contains
user32.dll
then you may be killed rather quickly in this scenario, depending on
whether the command(s) used is a "trigger" command that won't drive
ABENDXIT (SetConsoleCtrlHandler) at phase 1 PowerOff.
In my case, I've gathered logs from my PROD external monitor since
December. This PROD version, as well as all my other programs that
have an ABENDXIT, do NOT have SM_SHUTTINGDOWN assembled into it.
However, I've also been running a "CLONE" in parallel w/the PROD
version, the ONLY difference in source being:
.asm
GETSHUTSTATFLAGM EQU 1 ; (to imbed SM_SHUTTINGDOWN, else 0)
.lst (PROD)
2 IF GETSHUTSTATFLAGM EQ 1
2 ;* WARNING: INCLUDING THIS IN CODE WILL NOT(!) DRIVE ABENDXIT @ POWEROFF!!!...
2 INVOKE GetSystemMetrics,
2 SM_SHUTTINGDOWN ; x'2000'
2 ELSE
000008B5 B8 00000000 2 MOV EAX,0 ; NEVER UPDATE ABENDWB FROM HERE!
2 ENDIF
.lst (CLONE)
2 IF GETSHUTSTATFLAGM EQ 1
2 ;* WARNING: INCLUDING THIS IN CODE WILL NOT(!) DRIVE ABENDXIT @ POWEROFF!!!...
000008B5 68 00002000 * push +000002000h
000008BA E8 00000000 E * call GetSystemMetrics
2 INVOKE GetSystemMetrics,
2 SM_SHUTTINGDOWN ; x'2000'
2 ELSE
2 MOV EAX,0 ; NEVER UPDATE ABENDWB FROM HERE!
2 ENDIF
.map (PROD)
N/A
.map (CLONE)
0001:0000cfba _GetSystemMetrics@4 0040dfba f user32:user32.dll
5 in total.
and using a higher SLEEP interval (.499s; to induce more killings?).
The results are "very interesting":
0. log records are "paired" per run
. by PID; has a start and either an end OR a lost heartbeat record
1. the PROD runs
. 150 start records, 150 "paired" end records
. ZERO lost heartbeats detected (100% NOT killed)
. last one on NOV13 when SM_SHUTTINGDOWN was removed
. all detections via ABENDXIT
2. the CLONE runs
. 157 start records, 157 "paired" end records
. 68 lost heartbeats detected ( 57% NOT killed; just over HALF!)
. all allowed detections via SM_SHUTTINGDOWN
For the rc19 (ERROR_WRITE_PROTECT) problem, the external monitor
isn't started like WTS starts my other tasks (at startup opposed to
every 10min), so it doesn't need the SPECIAL TECHNIQUE I had to come
up with to preserve data integrity if the rc19 does NOT occur (which
is actually WORSE):
. if I'm a fraction of a second earlier, I actually start, log data,
then get killed (DUH! 1 SECOND B 4 the screen goes black and the
power is physically removed)
. I've also been on the other side of the fence, when I was started a
tenth AFTER(!) EV13; in this case, it didn't get very far. The single
output file only had the 1st .BAT ECHO. :(
Since an Event only lasts until the PID exits, but I need something
that would cover the length of a typical shutdown, I made this.
Now, I run an isolated program first, which fakes what ABENDXIT
would do; set ERRORLEVEL 9944-7. This way, the main program never
starts, so data integrity is no longer an issue.
Basically, I have a "global" .txt file containing the system TOD
and GetTickCount, written by the external monitor when IT gets its'
ABENDXIT driven. So, under WTS, if this isolated program runs, if,
after 3 SLEEP minimum (15ms) intervals, its' ABENDXIT handler is not
driven (possibly due to the next check) and SM_SHUTTINGDOWN is not
set (both checked after each interval), it reads the file, and, after
a few checks, if it's within a few seconds (default=30), then fake
the shut down detection myself. The .BAT sees the bad RC and exits.
One second later, the power is gone!!!
This works quite well on my machines. In my case, a WTS task runs
every 10min from 12:05. If I PowerOff at 12:04:36 (length of my
TESTFK, .wav, 5 of 7 seconds of blue screen, etc), based on an
external clock and EventLogs, WTS starts my task at 12:05:00.002 and
the power is removed at 12:05:03.715 (EV13). Since I now detect
shutdown myself with my program, and so don't start it, now there is
no chance of loss of data integrity. The .BAT ECHO (ie: NOT killed!)
even appends the date, time, and the fake RC to a .txt file:
CHECKSHU Tue 12/23/2014 12:05:03.20 TERMINATED by Ctl-C! / 9947
I have to say, though, that all this runs perfectly, in spite of
most everything else probably gone. I can envision why programs may
want to run here, but there should be an option in WTS for this, to
prevent loss of data integrity when killed. Of course, if ABENDXIT
was driven during this time, or SM_SHUTTINGDOWN was set, OR BOTH(!),
this would not be required. :)