StrokesPlus.net
Welcome Guest! To enable all features please Login or Register.

Notification

Icon
Error

Options
Go to last post Go to first unread
beholder  
#1 Posted : Saturday, August 24, 2019 3:36:00 PM(UTC)
beholder

Rank: Advanced Member

Reputation:

Groups: Approved
Joined: 8/9/2019(UTC)
Posts: 86
Slovakia

Thanks: 6 times
I left trace logging on during the whole time of testing and I got to some very large slowdowns during chrome+fb loading. Then S+ crashed. I am puttin this to Drive so you can see what was happening, I don't see anything special.

What perplexes me though is the line ScriptEngine.cs::Execute(): Too Many Script Errors
It's very common during the last few hours of running S+. Do I have some kind of problem or is it normal?

Log here: https://drive.google.com/open?id=1KLS4eFY1A8keRmMknBQHQuGrvLOdkPXF
Rob  
#2 Posted : Saturday, August 24, 2019 5:03:19 PM(UTC)
Rob

Rank: Administration

Reputation:

Groups: Translators, Members, Administrators
Joined: 1/11/2018(UTC)
Posts: 340
United States

Thanks: 5 times
Was thanked: 64 time(s) in 56 post(s)
Re: "Too Many Script Errors - Successful execution, resetting"

That's fine, it was just for my testing, it just means is reset the script error counter since a successful script executed. I named it "Too Many Script Errors" so I knew what part of the logic was for.

So a crash, can you send the event details from Event Viewer so I can see where in the code it crashed? There are usually two events, the first isn't useful, but the second one will have an error message and a call stack which tells me exactly what function crashed.
beholder  
#3 Posted : Saturday, August 24, 2019 5:32:26 PM(UTC)
beholder

Rank: Advanced Member

Reputation:

Groups: Approved
Joined: 8/9/2019(UTC)
Posts: 86
Slovakia

Thanks: 6 times
Here:

Application: StrokesPlus.net_Trace.exe
Framework Version: v4.0.30319
Description: The process was terminated due to an unhandled exception.
Exception Info: System.NullReferenceException
at StrokesPlus.net.Hooks.HookState.StartCancelTimer()
at StrokesPlus.net.Hooks.MouseHook.MouseProc(Int32, IntPtr, IntPtr)
at System.Windows.Forms.UnsafeNativeMethods.PeekMessage(MSG ByRef, System.Runtime.InteropServices.HandleRef, Int32, Int32, Int32)
at System.Windows.Forms.Application+ComponentManager.System.Windows.Forms.UnsafeNativeMethods.IMsoComponentManager.FPushMessageLoop(IntPtr, Int32, Int32)
at System.Windows.Forms.Application+ThreadContext.RunMessageLoopInner(Int32, System.Windows.Forms.ApplicationContext)
at System.Windows.Forms.Application+ThreadContext.RunMessageLoop(Int32, System.Windows.Forms.ApplicationContext)
at System.Windows.Forms.Application.Run(System.Windows.Forms.Form)
at StrokesPlus.net.Program.Main(System.String[])


Please note, this was during a really bad system slowdown. I get those when memory is quite full, a new application is being launched which uses a lot of disk drive, etc.
Rob  
#4 Posted : Saturday, August 24, 2019 6:12:04 PM(UTC)
Rob

Rank: Administration

Reputation:

Groups: Translators, Members, Administrators
Joined: 1/11/2018(UTC)
Posts: 340
United States

Thanks: 5 times
Was thanked: 64 time(s) in 56 post(s)
Hmm, I can see one potential race condition that could result in a crash.

I've updated that logic to hopefully prevent the exception, but also wrapped the start/stop cancel timer function bodies in a try/catch since it's technically a recoverable error, just might not have a cancel timeout for that stroke button down action in the worst case, next would be fine again. But the code change I made should also prevent it from happening anyway.
beholder  
#5 Posted : Saturday, August 24, 2019 6:57:57 PM(UTC)
beholder

Rank: Advanced Member

Reputation:

Groups: Approved
Joined: 8/9/2019(UTC)
Posts: 86
Slovakia

Thanks: 6 times
Jesus, [just an off topic question] how do you see race conditions? I was having a problem once with one software and it took me several years to figure out WTF is going on and how there MIGHT be a critical problem which was a race condition. How the hell do you actually see these in code? I don't consider myself a really good programmer but hey, come on, I can't be THAT bad?
beholder  
#6 Posted : Saturday, August 24, 2019 7:04:22 PM(UTC)
beholder

Rank: Advanced Member

Reputation:

Groups: Approved
Joined: 8/9/2019(UTC)
Posts: 86
Slovakia

Thanks: 6 times
btw you probably didn't make a new version available where I could download it
Rob  
#7 Posted : Saturday, August 24, 2019 7:38:17 PM(UTC)
Rob

Rank: Administration

Reputation:

Groups: Translators, Members, Administrators
Joined: 1/11/2018(UTC)
Posts: 340
United States

Thanks: 5 times
Was thanked: 64 time(s) in 56 post(s)
Haha, no I didn't upload it yet, I just updated the source code.

Race conditions are generally difficult to see. However, since I've written the whole program, I know the different pathways of events and code calls to be able to see how it could happen.

But it's also experience. I mean, it was a null reference error. That particular function is very simple and only has like three different things that are referenced. One which is only assigned within lock() sections, so the likelihood is nearly zero.

The other is more volatile, which is the matched application. That changes very frequently and is referenced in multiple locations. I can't really lock it due to the overall flow of events and places it is referenced...and to try to keep this .net version as fast as possible in these areas, I don't have a lot of safe code around certain performance critical functions.

So knowing this and looking at the code, it makes sense that under a heavy system load, a few events could happen near simultaneously due to things being queued up, etc.

Basically it was like this:

if(matchedAppliation != null) {
//Right here, between CPU thrashing/queue, matchedApplication was changed in another location (cleared, set to null), so now the next line will throw a null reference
Set timer delay to matchedApplication.CancelDelay
} else {
Use global cancelDelay
}

So instead I assigned the matchedApplication to a local var, and check that instead as well as use the local copy's CancelDelay value.

But I also wrapped the whole thing in a try/catch, so if there is still an exception, it just fails gracefully and sets the cancel timer to null.

Now it's not a big deal to try/catch here because it's not a performance critical area, but locking or try/catching around all matchedApplication references would not be good, since that needs to happen as fast as possible so if the app is ignored, the mouse hook can call the next hook so the mouse click happens right away..the goal is to make it very unlikely that someone notices S+ is there and hooking/examining every single mouse event.
beholder  
#8 Posted : Monday, August 26, 2019 10:43:39 AM(UTC)
beholder

Rank: Advanced Member

Reputation:

Groups: Approved
Joined: 8/9/2019(UTC)
Posts: 86
Slovakia

Thanks: 6 times
So I got it crashing again, this time with heavy GIMPing, disk trashing, low disk space and low memory. Perhaps the trace version could not write to log anymore and it crashed?

The trace log CRASH2 is here: https://drive.google.com/open?id=1KS04d1usQmWkp45PDvJLXCA2QgNlzegR

EV entry is this:
Application: StrokesPlus.net_Trace.exe
Framework Version: v4.0.30319
Description: The process was terminated due to an unhandled exception.
Exception Info: System.IO.IOException
at System.IO.__Error.WinIOError(Int32, System.String)
at System.IO.FileStream.WriteCore(Byte[], Int32, Int32)
at System.IO.FileStream.FlushInternalBuffer()
at System.IO.FileStream.Flush(Boolean)
at System.IO.FileStream.Flush()
at System.IO.StreamWriter.Flush(Boolean, Boolean)
at System.IO.StreamWriter.Flush()
at System.Diagnostics.TextWriterTraceListener.Flush()
at System.Diagnostics.TraceInternal.WriteLine(System.String)
at System.Diagnostics.Trace.WriteLineIf(Boolean, System.String)
at StrokesPlus.net.Code.ApplicationMatching.CriteriaMatched(StrokesPlus.net.Code.MatchCriteria, System.String)
at StrokesPlus.net.Code.ApplicationMatching.IgnoredApplicationMatched(System.Collections.Generic.List`1<StrokesPlus.net.Code.IgnoredApplication>, Boolean ByRef)
at StrokesPlus.net.Code.ApplicationMatching.IsWindowIgnored(IntPtr, Boolean ByRef)
at StrokesPlus.net.Hooks.WinEventHook.WinEventProc(IntPtr, UInt32, IntPtr, Int32, Int32, UInt32, UInt32)
at System.Windows.Forms.UnsafeNativeMethods.PeekMessage(MSG ByRef, System.Runtime.InteropServices.HandleRef, Int32, Int32, Int32)
at System.Windows.Forms.Application+ComponentManager.System.Windows.Forms.UnsafeNativeMethods.IMsoComponentManager.FPushMessageLoop(IntPtr, Int32, Int32)
at System.Windows.Forms.Application+ThreadContext.RunMessageLoopInner(Int32, System.Windows.Forms.ApplicationContext)
at System.Windows.Forms.Application+ThreadContext.RunMessageLoop(Int32, System.Windows.Forms.ApplicationContext)
at System.Windows.Forms.Application.Run(System.Windows.Forms.Form)
at StrokesPlus.net.Program.Main(System.String[])


Rob  
#9 Posted : Monday, August 26, 2019 12:34:19 PM(UTC)
Rob

Rank: Administration

Reputation:

Groups: Translators, Members, Administrators
Joined: 1/11/2018(UTC)
Posts: 340
United States

Thanks: 5 times
Was thanked: 64 time(s) in 56 post(s)
Yeah, that exception is coming from way down the pipeline inside of .NET's I/O trying to write the entry to the trace file.

I would say at this point you probably don't need to run the trace version. We definitely found that X1 was in a stuck state of down, and saw it in the logs.

I honestly feel like it's due to that foreground script and a race condition (or a hardware problem with the mouse itself), but if it's not there isn't much more I could probably glean from the trace file.

Edited by user Monday, August 26, 2019 12:37:40 PM(UTC)  | Reason: Not specified

beholder  
#10 Posted : Monday, August 26, 2019 1:36:35 PM(UTC)
beholder

Rank: Advanced Member

Reputation:

Groups: Approved
Joined: 8/9/2019(UTC)
Posts: 86
Slovakia

Thanks: 6 times
Hmm, perhaps for the future you can just keep stuff in memory if it cant be immediately written down. And attempt periodically to do so. It's just a few lines usually and then the disk space clears up. FYI, Gimp was taking too much with editing an extensively large image.
Rob  
#11 Posted : Monday, August 26, 2019 2:02:54 PM(UTC)
Rob

Rank: Administration

Reputation:

Groups: Translators, Members, Administrators
Joined: 1/11/2018(UTC)
Posts: 340
United States

Thanks: 5 times
Was thanked: 64 time(s) in 56 post(s)
To be honest, tracing or doing anything really when disk space or RAM are severely limited aren't really useful as there are so many things which can go wrong outside of the application which I have no control over.

This is just a utility app, not like bank teller code or stock trading software :)

Writing code to be highly resilient is very time consuming.
beholder  
#12 Posted : Monday, August 26, 2019 4:33:57 PM(UTC)
beholder

Rank: Advanced Member

Reputation:

Groups: Approved
Joined: 8/9/2019(UTC)
Posts: 86
Slovakia

Thanks: 6 times
sure, good thing we at least know what was the latest crash about.
beholder  
#13 Posted : Friday, August 30, 2019 9:39:04 AM(UTC)
beholder

Rank: Advanced Member

Reputation:

Groups: Approved
Joined: 8/9/2019(UTC)
Posts: 86
Slovakia

Thanks: 6 times
I got 2 more crashes earlier yesterday while still at extreme system conditions, perhaps you can make some more sense of them:

Application: StrokesPlus.net.exe
Framework Version: v4.0.30319
Description: The process was terminated due to an unhandled exception.
Exception Info: System.NullReferenceException
at StrokesPlus.net.Hooks.MouseHook.StopMouseHook()
at StrokesPlus.net.Tray.TrayManager.Unload()
at StrokesPlus.net.frmSurface.CloseProgram(System.Object)
at System.Threading.TimerQueueTimer.CallCallbackInContext(System.Object)
at System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
at System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
at System.Threading.TimerQueueTimer.CallCallback()
at System.Threading.TimerQueueTimer.Fire()
at System.Threading.TimerQueue.FireNextTimers()
at System.Threading.TimerQueue.AppDomainTimerCallback(Int32)


Application: StrokesPlus.net.exe
Framework Version: v4.0.30319
Description: The process was terminated due to an unhandled exception.
Exception Info: System.NullReferenceException
at StrokesPlus.net.Hooks.MouseHook.StopMouseHook()
at StrokesPlus.net.Tray.TrayManager.Unload()
at StrokesPlus.net.frmSurface.CloseProgram(System.Object)
at System.Threading.TimerQueueTimer.CallCallbackInContext(System.Object)
at System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
at System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
at System.Threading.TimerQueueTimer.CallCallback()
at System.Threading.TimerQueueTimer.Fire()
at System.Threading.TimerQueue.FireNextTimers()
at System.Threading.TimerQueue.AppDomainTimerCallback(Int32)
Rob  
#14 Posted : Friday, August 30, 2019 10:02:33 AM(UTC)
Rob

Rank: Administration

Reputation:

Groups: Translators, Members, Administrators
Joined: 1/11/2018(UTC)
Posts: 340
United States

Thanks: 5 times
Was thanked: 64 time(s) in 56 post(s)
The call stack shows:

at StrokesPlus.net.Tray.TrayManager.Unload()

Did these crashes/exceptions occur when S+ was being closed?
Rob  
#15 Posted : Friday, August 30, 2019 10:09:43 AM(UTC)
Rob

Rank: Administration

Reputation:

Groups: Translators, Members, Administrators
Joined: 1/11/2018(UTC)
Posts: 340
United States

Thanks: 5 times
Was thanked: 64 time(s) in 56 post(s)
Never mind, I see the caller to Unload is CloseProgram, which is a timer callback to exit the application under one of the following conditions:

1. Loading of settings file failed
2. The script engine failed to initialize

Either way, I have added some code to prevent this particular error. It was trying to remove the mouse hook, but the mouse hook form no longer (or never did) exists while it's exiting S+.
beholder  
#16 Posted : Wednesday, September 4, 2019 3:44:02 AM(UTC)
beholder

Rank: Advanced Member

Reputation:

Groups: Approved
Joined: 8/9/2019(UTC)
Posts: 86
Slovakia

Thanks: 6 times
I got some more crashes, this time I got weird .net fail messages just before the actual S+ crash (will post them in different posts in this thread):
Application: StrokesPlus.net.exe
Framework Version: v4.0.30319
Description: The process was terminated due to an unhandled exception.
Exception Info: System.NullReferenceException
at StrokesPlus.net.Controls.tabPreferences.prefCheckClick(System.Object, System.EventArgs)
at System.Windows.Forms.CheckBox.OnCheckedChanged(System.EventArgs)
at System.Windows.Forms.CheckBox.set_CheckState(System.Windows.Forms.CheckState)
at System.Windows.Forms.CheckBox.set_Checked(Boolean)
at StrokesPlus.net.Controls.tabPreferences.SetPrefCheck()
at StrokesPlus.net.Controls.tabPreferences.SetPreferences()
at StrokesPlus.net.Controls.tabPreferences..ctor(StrokesPlus.net.Code.Settings)
at StrokesPlus.net.Forms.frmMain..ctor()
at StrokesPlus.net.Code.ServerState.OpenMainFormThread()
at StrokesPlus.net.Code.ServerState+<>c.<OpenSettings>b__61_0()
at System.Threading.ThreadHelper.ThreadStart_Context(System.Object)
at System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
at System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
at System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)
at System.Threading.ThreadHelper.ThreadStart()
beholder  
#17 Posted : Wednesday, September 4, 2019 3:47:04 AM(UTC)
beholder

Rank: Advanced Member

Reputation:

Groups: Approved
Joined: 8/9/2019(UTC)
Posts: 86
Slovakia

Thanks: 6 times
This was the 1st .net fail:

System.ArgumentException: Controls created on one thread cannot be parented to a control on a different thread.
at System.Windows.Forms.Control.ControlCollection.Add(Control value)
at StrokesPlus.net.Forms.frmMain.AssignScriptControl(Control target, BaseAction baseAction)
at StrokesPlus.net.Controls.BeforeAfterActionEditor.SetScript()
at StrokesPlus.net.Controls.BeforeAfterActionEditor.LoadApp(Application app)
at StrokesPlus.net.Controls.tabApplications.LoadApp()
at StrokesPlus.net.Controls.tabApplications.lvApps_SelectedIndexChanged(Object sender, EventArgs e)
at System.Windows.Forms.ListView.OnSelectedIndexChanged(EventArgs e)
at System.Windows.Forms.ListView.WmReflectNotify(Message& m)
at System.Windows.Forms.ListView.WndProc(Message& m)
at System.Windows.Forms.Control.ControlNativeWindow.OnMessage(Message& m)
at System.Windows.Forms.Control.ControlNativeWindow.WndProc(Message& m)
at System.Windows.Forms.NativeWindow.Callback(IntPtr hWnd, Int32 msg, IntPtr wparam, IntPtr lparam)

<message truncated, the rest was just drivel>
beholder  
#18 Posted : Wednesday, September 4, 2019 3:48:21 AM(UTC)
beholder

Rank: Advanced Member

Reputation:

Groups: Approved
Joined: 8/9/2019(UTC)
Posts: 86
Slovakia

Thanks: 6 times
This was the 2nd .net fail. There was also a 3rd one but I thought that 2 is probably just enough because they seem to generate based on each-other.

************** Exception Text **************
System.NullReferenceException: Object reference not set to an instance of an object.
at StrokesPlus.net.Controls.BeforeAfterActionEditor.SetScript()
at StrokesPlus.net.Controls.BeforeAfterActionEditor.LoadApp(Application app)
at StrokesPlus.net.Controls.tabApplications.LoadApp()
at StrokesPlus.net.Controls.tabApplications.lvApps_SelectedIndexChanged(Object sender, EventArgs e)
at System.Windows.Forms.ListView.OnSelectedIndexChanged(EventArgs e)
at System.Windows.Forms.ListView.WmReflectNotify(Message& m)
at System.Windows.Forms.ListView.WndProc(Message& m)
at System.Windows.Forms.Control.ControlNativeWindow.OnMessage(Message& m)
at System.Windows.Forms.Control.ControlNativeWindow.WndProc(Message& m)
at System.Windows.Forms.NativeWindow.Callback(IntPtr hWnd, Int32 msg, IntPtr wparam, IntPtr lparam)

Rob  
#19 Posted : Thursday, September 5, 2019 2:13:18 PM(UTC)
Rob

Rank: Administration

Reputation:

Groups: Translators, Members, Administrators
Joined: 1/11/2018(UTC)
Posts: 340
United States

Thanks: 5 times
Was thanked: 64 time(s) in 56 post(s)
Sorry, I've been very busy with work and haven't had a chance to look into any forum stuff.

Can you reproduce this crash? I'm not even sure how it would happen.
beholder  
#20 Posted : Thursday, September 5, 2019 5:49:55 PM(UTC)
beholder

Rank: Advanced Member

Reputation:

Groups: Approved
Joined: 8/9/2019(UTC)
Posts: 86
Slovakia

Thanks: 6 times
Not a chance. It's alway some kind of random racing when the system is stressed, so it's difficult to reproduce. But when I do, you'll know it. All I remember was getting the .net failings first and then when NOT clicking ignore on one of them there was the S+ crash.
Users browsing this topic
Forum Jump  
You cannot post new topics in this forum.
You cannot reply to topics in this forum.
You cannot delete your posts in this forum.
You cannot edit your posts in this forum.
You cannot create polls in this forum.
You cannot vote in polls in this forum.