Win7; detecting shutdown in an MASM program

[MtheK]

  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...

[GoneFishing]

  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  ;)

[dedndave]

  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" ?????

[Magnum]

  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

[MtheK]

  Hardly; it's the DSNTODAY system as described in my very first post:

http://masm32.com/board/index.php?topic=2117.0

[dedndave]

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

[MtheK]

  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:

Code Select Expand


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.

[MtheK]

  FYI: capturing the apparent force-killer at PowerOff appears to be in DllHost.exe+12E9:

Code Select Expand


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.

[MtheK]

  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?

[MtheK]

  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.

[MtheK]

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.

[MtheK]

  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...

[MtheK]

  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.

[herge]

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

[MtheK]

  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).

Code Select Expand



  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.