【问题标题】:Delphi thread created in suspended mode gets started by itself on windows 2012 server在挂起模式下创建的 Delphi 线程在 Windows 2012 服务器上自行启动
【发布时间】:2016-03-11 22:02:34
【问题描述】:

过去几天我一直在为一个我无法理解的错误而苦苦挣扎。 这仅在 Windows 2012 服务器(64 位) 中发生,而(至少)在以下 Windows 版本上不会发生:Windows XP(32 位)、Windows 7(32 和 64 位)、Windows 8(64 位)、Windows 8.1(64 位)、Windows 10(64 位)、Windows 2003 Server(32 位)。

请注意,在所有情况下,应用程序都是 32 位二进制文​​件。

当应用程序启动时,它会初始化一些东西,最后它会创建一系列线程,所有线程都处于挂起模式,以便我以后可以手动启动它们。

在下面的代码中,可以预期 t 在睡眠后启动。 然而,当我尝试在线程上显式调用 Start 时,我意识到它已经(不知何故)已经启动,导致 线程已经启动异常(其中考虑到线程已经启动就可以了)。

// some initialization code is run before this, but nothing directly related
procedure foo;
var
  t : TThread; // note that there can be no reference to this thread from the outside since it's a local var
begin
  t := TMyThread.Create(true); // TMyThread

  sleep(3000); // time window of 3 seconds where the thread shouldn't have started

  t.Start; // now i want to start it manually, but the thread has already been started soon after it has been created
end;

常规(虚拟)匿名线程也会发生同样的情况,所以这不是 TMyThread 的错:

// some initialization code is run before this, but nothing directly related
procedure foo;
var
  t : TThread; // note that there can be no reference to this thread from the outside since it's a local var
begin
  t := TThread.CreateAnonymousThread( // to avoid using my possibly faulted TMyThread class, I'm now testing with a regular anonymous thread and the problem persists
    procedure begin 
      log('Hi from anon thread');
      sleep(5000); // to make it live 5 seconds for testing purposes
    end); 

  sleep(3000); // time window of 3 seconds where the thread shouldn't have started

  t.Start; // now i want to start it manually, but the thread has already been started soon after it has been created
end;

Windows 2012 服务器中是否存在一些我缺少的关于线程管理的机制?

日志摘录

以下是健康日志文件的摘录。您可以看到 start 方法如何调用 startThreads 方法,该方法依次创建第一个线程。下一行表示从 CMP_AbstractThread 的构造函数进行的调用。 evInitialized 和 evStarted 是在 CMP_AbstractThread 的构造函数中创建的 TEvents。

12/03/2016 20:28:47.336: LOG_DEBUG  @ PID=5576 ThreadID=5188 (TExternalThread) @ CMPPS_Application.start: start ...
12/03/2016 20:28:47.336: LOG_DEBUG  @ PID=5576 ThreadID=5188 (TExternalThread) @ CMPPS_Application.createThreads: createThreads ...
12/03/2016 20:28:47.352: LOG_FINEST @ PID=5576 ThreadID=5188 (TExternalThread) @ CMP_AbstractThread.: (PID=5576 ThreadID=0 (CMPP_EventsThread)).Create ...
12/03/2016 20:28:47.352: LOG_FINEST @ PID=5576 ThreadID=5188 (TExternalThread) @ CMP_AbstractThread.: (PID=5576 ThreadID=6084 (CMPP_EventsThread)).Create.
12/03/2016 20:28:47.352: LOG_DEBUG  @ PID=5576 ThreadID=5188 (TExternalThread) @ CMP_AbstractThread.: (PID=5576 ThreadID=6084 (CMPP_EventsThread).evInitialized).Create ...
12/03/2016 20:28:47.352: LOG_DEBUG  @ PID=5576 ThreadID=5188 (TExternalThread) @ CMP_AbstractThread.: (PID=5576 ThreadID=6084 (CMPP_EventsThread).evInitialized).Create.
12/03/2016 20:28:47.352: LOG_DEBUG  @ PID=5576 ThreadID=5188 (TExternalThread) @ CMP_AbstractThread.: (PID=5576 ThreadID=6084 (CMPP_EventsThread).evInitialized).resetEvent ...
12/03/2016 20:28:47.352: LOG_DEBUG  @ PID=5576 ThreadID=5188 (TExternalThread) @ CMP_AbstractThread.: (PID=5576 ThreadID=6084 (CMPP_EventsThread).evInitialized).resetEvent.
12/03/2016 20:28:47.352: LOG_DEBUG  @ PID=5576 ThreadID=5188 (TExternalThread) @ CMP_AbstractThread.: (PID=5576 ThreadID=6084 (CMPP_EventsThread).evStarted).Create ...
12/03/2016 20:28:47.352: LOG_DEBUG  @ PID=5576 ThreadID=5188 (TExternalThread) @ CMP_AbstractThread.: (PID=5576 ThreadID=6084 (CMPP_EventsThread).evStarted).Create.
12/03/2016 20:28:47.352: LOG_DEBUG  @ PID=5576 ThreadID=5188 (TExternalThread) @ CMP_AbstractThread.: (PID=5576 ThreadID=6084 (CMPP_EventsThread).evStarted).resetEvent ...
12/03/2016 20:28:47.352: LOG_DEBUG  @ PID=5576 ThreadID=5188 (TExternalThread) @ CMP_AbstractThread.: (PID=5576 ThreadID=6084 (CMPP_EventsThread).evStarted).resetEvent.

以下是 Windows 2012 会话的摘录。您可以看到线程甚至在它自己的构造函数完成之前就开始了。来自线程 Execute 方法的日志行来自线程 5864,该线程仍在创建中。在这种特定情况下,异常甚至没有等待构造函数完成(通常是这样)。看起来好像 TThread 是用 False 而不是 True 创建的。

12/03/2016 20:29:31.813: LOG_DEBUG  @ PID=3796 ThreadID=4460 (TExternalThread) @ CMPPS_Application.start: start ...
12/03/2016 20:29:31.813: LOG_DEBUG  @ PID=3796 ThreadID=4460 (TExternalThread) @ CMPPS_Application.createThreads: createThreads ...
12/03/2016 20:29:31.813: LOG_FINEST @ PID=3796 ThreadID=4460 (TExternalThread) @ CMP_AbstractThread.: (PID=3796 ThreadID=0 (CMPP_EventsThread)).Create ...
12/03/2016 20:29:31.813: LOG_FINEST @ PID=3796 ThreadID=4460 (TExternalThread) @ CMP_AbstractThread.: (PID=3796 ThreadID=5864 (CMPP_EventsThread)).Create.
12/03/2016 20:29:31.813: LOG_DEBUG  @ PID=3796 ThreadID=4460 (TExternalThread) @ CMP_AbstractThread.: (PID=3796 ThreadID=5864 (CMPP_EventsThread).evInitialized).Create ...
12/03/2016 20:29:31.813: LOG_DEBUG  @ PID=3796 ThreadID=4460 (TExternalThread) @ CMP_AbstractThread.: (PID=3796 ThreadID=5864 (CMPP_EventsThread).evInitialized).Create.
12/03/2016 20:29:31.813: LOG_DEBUG  @ PID=3796 ThreadID=4460 (TExternalThread) @ CMP_AbstractThread.: (PID=3796 ThreadID=5864 (CMPP_EventsThread).evInitialized).resetEvent ...
12/03/2016 20:29:31.813: LOG_DEBUG  @ PID=3796 ThreadID=4460 (TExternalThread) @ CMP_AbstractThread.: (PID=3796 ThreadID=5864 (CMPP_EventsThread).evInitialized).resetEvent.

12/03/2016 20:29:31.813: LOG_FINEST @ PID=3796 ThreadID=5864 (CMPP_EventsThread) @ CMP_AbstractThread.Execute: (PID=3796 ThreadID=5864 (CMPP_EventsThread)) Executed.
12/03/2016 20:29:31.813: LOG_NORMAL @ PID=3796 ThreadID=5864 (CMPP_EventsThread) @ CMP_AbstractThread.Execute: (PID=3796 ThreadID=5864 (CMPP_EventsThread)) Down.

12/03/2016 20:29:31.828: LOG_DEBUG  @ PID=3796 ThreadID=4460 (TExternalThread) @ CMP_AbstractThread.: (PID=3796 ThreadID=5864 (CMPP_EventsThread).evStarted).Create ...
12/03/2016 20:29:31.828: LOG_DEBUG  @ PID=3796 ThreadID=4460 (TExternalThread) @ CMP_AbstractThread.: (PID=3796 ThreadID=5864 (CMPP_EventsThread).evStarted).Create.
12/03/2016 20:29:31.828: LOG_DEBUG  @ PID=3796 ThreadID=4460 (TExternalThread) @ CMP_AbstractThread.: (PID=3796 ThreadID=5864 (CMPP_EventsThread).evStarted).resetEvent ...
12/03/2016 20:29:31.828: LOG_DEBUG  @ PID=3796 ThreadID=4460 (TExternalThread) @ CMP_AbstractThread.: (PID=3796 ThreadID=5864 (CMPP_EventsThread).evStarted).resetEvent.

代码摘录

constructor CMP_AbstractThread.Create(suspended : boolean);
begin
  inherited Create(suspended); // this one sets up threadName
  FEvInitialized := CMP_Event.Create(threadName, 'evInitialized');
  FEvInitialized.ResetEvent;
  FEvStarted := CMP_Event.Create(threadName, 'evStarted');
  FEvStarted.ResetEvent;
end;

Constructor CMP_Thread.Create(suspended : boolean);
Begin
  log(LOG_FINEST, format('(%s).Create ...', [ThreadInfo]));
  inherited Create(suspended);
  FThreadName := threadInfo;
  log(LOG_FINEST, format('(%s).Create.', [ThreadName]));
End;

procedure CMPPS_Application.createThreads;
begin
  logGuard('createThreads', procedure begin
    FEventsThread := CMPP_EventsThread(CMPP_EventsThread.Create(true)
      .setDbConnection(FDB)
      .setLogger(GEventsLogger)
      .setDelay(MP_EVENTS_THREAD_DELAY));
  end);
end;

CMPP_EventsThread = class(CMPC_EventsThread)
  // all the following methods are inherited from different layers
  // Create(boolean) is inherited directly from CMP_AbstractThread
  // setDbConnection(IMP_DBConnection)
  // setLogger(IMP_Logger)
  // setDelay(integer)
end;

【问题讨论】:

  • 这看起来很不可信。我们可以有一个完整的程序吗?
  • 我担心你会问这个。当然可以,但是我需要一点时间来提取一个正在运行的演示。
  • 正如我所怀疑的,演示似乎运行良好。所以,问题一定出在线程创建之前的代码中。但是那个对我的线程一无所知的代码(它甚至是一个局部变量)怎么能做任何事情来让它在创建时开始呢?看起来好像发生了一些事情,使未来的线程自动启动,无论它们被创建为挂起。对这样的场景有任何想法,其中初始化代码(由上面的注释行表示)可以使这样的事情发生吗?请记住,这只发生在 2012 服务器上。
  • 我认为缺陷可能出在您的代码中。我会把注意力集中在那里。
  • 可能是内存覆盖错误。这可能仅在特定的硬件/操作系统组合上发生(或表现出来)。您是否尝试过开启所有运行时错误检测、溢出和范围检查?

标签: multithreading delphi delphi-xe windows-server-2012 delphi-10-seattle


【解决方案1】:

您所描述的在正常情况下是相当不可能的。如果TThread 构造函数的ACreateSuspended 参数为True,则线程创建为挂起状态。没有如果,ands,或buts about that。暂停的线程不能自发启动。

匿名线程总是被创建为挂起的。

假设您在有效的TThread 对象上调用TThread.Start()Start()在以下任一情况下引发异常:

  1. FCreateSuspended 成员为 False。如果ACreateSuspended 参数为True,则此成员在TThread 构造函数中设置为True,并由Start() 设置为False。您只能拨打一次Start()

  2. FFinished 成员为 True。在调用TThread.Execute()TThread.DoTerminate() 后,该值设置为True,这意味着线程已经运行完成。你不能在终止的线程上调用Start()

  3. FExternalThread 成员为 True。这是为TThread.GetCurrentThread() 返回的TThread 对象设置的。你不能在你没有明确Create()的线程上调用Start()

  4. 以上条件都可以,但是底层OS线程(由TThread.Handle属性表示)没有成功从挂起状态转换到运行状态。 唯一可能发生的方式是,如果您的代码中的某些内容正在调用 TThread.Suspend()TThread.Resume()(或者更糟糕的是,某些内容正在直接调用 Win32 API SuspendThread()ResumeThread())来更改在您调用 TThread.Start() 之前线程的暂停计数。

鉴于您展示的示例代码,这些条件是不可能的。所以问题必须与你没有显示的代码有关。

【讨论】:

  • 1) +1 用于对引发异常的精确描述。 2)我不担心引发异常,因为它与事物的状态一致(线程已经开始)。在这种情况下,我们显然是在你提到的第一种情况下 3)如果你必须编写在我的 sn-p 之前运行的代码来强制这个异常,你会怎么做? 4)我们已经使用这个应用程序将近 8 年了,不间断,至少 30 次安装 7x24x365,我们从未遇到过这个问题。为什么它只能发生在 Windows 2012 服务器(64 位)上?
  • 深入研究我评论的第 3 点,并引用您的“在正常情况下”:您认为在这种情况下会发生什么情况?当我看到即使在本地引用的“虚拟”匿名线程上也不断发生同样的事情时,我认输了。我没有看到我可以做些什么来产生这种异常。
  • 我能想到一些可能性,但我不想在没有更多信息的情况下进行推测。如果您进入“项目选项”并启用“调试 DCU”,您可以进入 Start() 的源代码,并查看它在什么情况下失败。我怀疑最有可能的罪魁祸首是 ResumeThread() 返回一个非 1 的值(线程从挂起过渡到运行)。
  • 目前我很难在服务器上设置调试会话。尽管如此,我很清楚,条件是 1) 在您的列表中。我对此毫不怀疑,因为我实际上可以看到线程正在运行(它们正在生成日志条目,正在做它们应该做的事情)。我不太想知道为什么我的Start() 失败了,就像想知道线程为什么开始一样。关于您不愿推测,请随意。不会造成任何伤害。
  • 正如我在回答中所描述的,Start() 可能会以几种不同的方式失败。它在您的项目中失败的事实意味着某些东西在您背后错误地处理了您的线程。至少通过进入Start() 的源代码,您可以了解原因。但是,您创建的挂起线程正在运行这一事实意味着要么有东西挂钩CreateThread() 本身以禁用CREATE_SUSPENDED 标志,要么有东西过早地调用TThread.Resume()/ResumeThread()。真的很难知道发生了什么,因为您没有测试用例来重现它。
猜你喜欢
  • 1970-01-01
  • 1970-01-01
  • 1970-01-01
  • 1970-01-01
  • 2014-08-28
  • 1970-01-01
  • 2021-05-09
  • 2019-09-01
  • 2017-09-02
相关资源
最近更新 更多