windbg - System.Configuration.ConfigurationErrorsException 예외 분석 방법
지난 글에서,
어느 순간부터 닷넷 응용 프로그램 실행 시 System.Configuration.ConfigurationErrorsException 예외가 발생한다면?
; https://www.sysnet.pe.kr/2/0/12388
default 파일로 덮어쓰는 방법을 제시했는데, 혹시 어느 config 설정에서 오류가 발생했는지 가능한 분석 방법이 있지 않을까요? 개인적으로는, 메모리 덤프를 뜨는 정도가 생각나는군요. ^^
아쉽게도 문제가 되었던 그 컴퓨터를 제가 접근할 수 없어 정확한 오류 지점이나 원인을 밝힐 수는 없었습니다. (폐쇄적인 고객사라서. ^^;)
대신 비슷하게나마 재현 상황을 만들어 분석을 해볼까 하는데요. 그래서 다음과 같이 간단하게 (문제가 있는) app.config 파일을 만들어,
<?xml version="1.0" encoding="utf-8" ?>
<configuration>
<configSections>
<section name="system.diagnostics" type="My.Diagnostics, MyLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089"/>
</configSections>
<system.diagnostics>
</system.diagnostics>
</configuration>
이를 사용하는 코드와 함께 구성해,
using System.Diagnostics;
namespace ConsoleApp
{
class Program
{
private readonly static TraceSource traceSource = new TraceSource("ConsoleApp", SourceLevels.All);
static void Main(string[] args)
{
traceSource.TraceEvent(TraceEventType.Information, 0, "Hello, world!");
}
}
}
실행해 보면 이런 오류가 이벤트 로그에 남습니다.
Application: ConsoleApp.exe
Framework Version: v4.0.30319
Description: The process was terminated due to an unhandled exception.
Exception Info: System.Configuration.ConfigurationErrorsException
at System.Configuration.ConfigurationSchemaErrors.ThrowIfErrors(Boolean)
at System.Configuration.BaseConfigurationRecord.ThrowIfParseErrors(System.Configuration.ConfigurationSchemaErrors)
at System.Configuration.BaseConfigurationRecord.ThrowIfInitErrors()
at System.Configuration.ClientConfigurationSystem.EnsureInit(System.String)
Exception Info: System.Configuration.ConfigurationErrorsException
at System.Configuration.ClientConfigurationSystem.EnsureInit(System.String)
at System.Configuration.ClientConfigurationSystem.PrepareClientConfigSystem(System.String)
at System.Configuration.ClientConfigurationSystem.System.Configuration.Internal.IInternalConfigSystem.GetSection(System.String)
at System.Configuration.ConfigurationManager.GetSection(System.String)
at System.Configuration.PrivilegedConfigurationManager.GetSection(System.String)
at System.Diagnostics.DiagnosticsConfiguration.GetConfigSection()
at System.Diagnostics.DiagnosticsConfiguration.Initialize()
at System.Diagnostics.DiagnosticsConfiguration.get_Sources()
at System.Diagnostics.TraceSource.Initialize()
at System.Diagnostics.TraceSource.TraceEvent(System.Diagnostics.TraceEventType, Int32, System.String)
at ConsoleApp.Program.Main(System.String[])
뭐 이 정도면 대충 비슷한 것 같습니다. ^^
자, 그럼 이제 어디가 정확히 문제인지 모른다고 가정하고 System.Configuration.ConfigurationErrorsException 예외가 발생했을 때 덤프를 뜨도록
procdump를 사용할 수 있습니다. 문제는, 저 예외가 실행 후 여유를 갖고 발생하는 것이 아닌, 곧바로 발생하는 것이라서 procdump에 -w 옵션을 주어 미리 실행해 두어야 합니다. (또는
-i 옵션으로, 또는
"Image File Execution Options" 설정으로.)
c:\temp> procdump -e 1 -f Exception -ma -w ConsoleApp.exe
게다가 -w 옵션은 단순히 빠르게 폴링하는 방식이라서 그 순간을 놓치기도 하므로 다음과 같이 그냥 종료하는 상황이 발생합니다.
c:\temp> procdump -e 1 -f Exception -ma -w ConsoleApp.exe
ProcDump v9.0 - Sysinternals process dump utility
Copyright (C) 2009-2017 Mark Russinovich and Andrew Richards
Sysinternals - www.sysinternals.com
Waiting for process named ConsoleApp.exe...
[12:38:25] Multiple processes match the specified name.
운이 없다면 계속 재실행하면서 덤프가 떠질 때까지 반복해야 하는데, 어쨌든 정상적으로 진행이 되었다면 이런 메시지를 보게 될 것입니다.
c:\temp> procdump -e 1 -f Exception -ma -w ConsoleApp.exe
ProcDump v9.0 - Sysinternals process dump utility
Copyright (C) 2009-2017 Mark Russinovich and Andrew Richards
Sysinternals - www.sysinternals.com
Waiting for process named ConsoleApp.exe...
Process: ConsoleApp.exe (15556)
Process image: C:\temp\ConsoleApp\ConsoleApp\bin\Debug\ConsoleApp.exe
CPU threshold: n/a
Performance counter: n/a
Commit threshold: n/a
Threshold seconds: n/a
Hung window check: Disabled
Log debug strings: Disabled
Exception monitor: First Chance+Unhandled
Exception filter: [Includes]
*Exception*
[Excludes]
Terminate monitor: Disabled
Cloning type: Disabled
Concurrent limit: n/a
Avoid outage: n/a
Number of dumps: 1
Dump folder: c:\temp\
Dump filename/mask: PROCESSNAME_YYMMDD_HHMMSS
Queue to WER: Disabled
Kill after dump: Disabled
Press Ctrl-C to end monitoring without terminating the process.
CLR Version: v4.0.30319
[12:38:30] Exception: E0434F4D.System.Configuration.ConfigurationErrorsException ("Section or group name 'system.diagnostics' is already defined. Updates to this may only occur at the configuration level where it is defined.")
[12:38:30] Dump 1 initiated: c:\temp\ConsoleApp.exe_201029_123830.dmp
[12:38:30] Dump 1 writing: Estimated dump file size is 99 MB.
[12:38:30] Dump 1 complete: 99 MB written in 0.2 seconds
[12:38:30] Dump count reached.
그나저나, 이벤트 로그와는 달리 위의 procdump 출력에는 "system.diagnostics" 쪽 설정에 오류가 있다고 알려주고 있습니다. 덤프를 뜨는 것만도 이렇게 문제가 해결되는군요. ^^
(덤프를 생성해 준 담당자가 저 메시지를 보았을 수 있겠지만 문제를 인식하지는 못했을 것입니다. 또는 여러 가지 경우를 가정해서) 그래도 모른다고 했을 때, 문제 파악을 위해 덤프 파일을 windbg로 분석해 보겠습니다.
0:000> .loadby sos clr
0:000> !clrstack
OS Thread Id: 0x95b0 (0)
Child SP IP Call Site
00afef54 771d164c [HelperMethodFrame: 00afef54]
00aff004 71b776a0 System.Configuration.ConfigurationSchemaErrors.ThrowIfErrors(Boolean)
00aff018 71ad4415 System.Configuration.BaseConfigurationRecord.ThrowIfParseErrors(System.Configuration.ConfigurationSchemaErrors)
00aff024 71ace39a System.Configuration.BaseConfigurationRecord.ThrowIfInitErrors()
00aff028 71acdb0d System.Configuration.ClientConfigurationSystem.EnsureInit(System.String)
00aff06c 71acd9b2 System.Configuration.ClientConfigurationSystem.PrepareClientConfigSystem(System.String)
00aff078 71acd944 System.Configuration.ClientConfigurationSystem.System.Configuration.Internal.IInternalConfigSystem.GetSection(System.String)
00aff08c 71ad6743 System.Configuration.ConfigurationManager.GetSection(System.String)
00aff098 6fa933c6 System.Configuration.PrivilegedConfigurationManager.GetSection(System.String)
00aff0a8 6fa945bf System.Diagnostics.DiagnosticsConfiguration.GetConfigSection()
00aff0ac 6fa952ea System.Diagnostics.DiagnosticsConfiguration.Initialize()
00aff0dc 6fa8b3d7 System.Diagnostics.DiagnosticsConfiguration.get_Sources()
00aff0e8 6fa8b1f2 System.Diagnostics.TraceSource.Initialize()
00aff130 6fa64757 System.Diagnostics.TraceSource.TraceEvent(System.Diagnostics.TraceEventType, Int32, System.String)
00aff184 012008d0 ConsoleApp2.Program.Main(System.String[]) [C:\temp\ConsoleApp2\ConsoleApp2\Program.cs @ 18]
00aff300 71f3f036 [GCFrame: 00aff300]
그러고 보니, System.Configuration.ConfigurationManager.GetSection 등의 메서드에서 System.String 인자로 받은 것이 아마도 문제가 되는 시점의 section 이름일 수 있습니다. 따라서 운이 좋다면
!dso 명령어 만으로,
0:000> !dso
OS Thread Id: 0x95b0 (0)
ESP/REG Object Name
00AFE71C 02c0d1d4 System.Configuration.ConfigurationErrorsException
00AFEEB8 02c0d1d4 System.Configuration.ConfigurationErrorsException
00AFEEF8 02c0d1d4 System.Configuration.ConfigurationErrorsException
00AFEF48 02c078bc System.Configuration.ConfigurationSchemaErrors
00AFEF4C 02bc272c System.String system.diagnostics
00AFEF78 02c078bc System.Configuration.ConfigurationSchemaErrors
00AFEF80 02bc272c System.String system.diagnostics
00AFEFD0 02c0d1d4 System.Configuration.ConfigurationErrorsException
00AFEFE0 02c0d1d4 System.Configuration.ConfigurationErrorsException
...[생략]...
00AFF74C 03bc2338 System.Object[] (System.Object[])
00AFF794 03bc2338 System.Object[] (System.Object[])
00AFF8A4 02bc1238 System.SharedStatics
문제를 파악할 수 있습니다. 혹은, 정확하게 100% 확신을 갖고 싶다면 지리한 콜 스택 분석을 해야 합니다.
x64 콜 스택 인자 추적과 windbg의 Child-SP, RetAddr, Args to Child 값 확인
; https://www.sysnet.pe.kr/2/0/10832
참고로, 이 글에서처럼 System.Diagnostics.TraceSource.Initialize 등의 호출 스택을 가지면서 ConfigurationErrorsException 예외를 갖는 경우에 대한 시나리오를 굳이 생각해 본다면... 아마도 특정 응용 프로그램을 설치 시 다음과 같은 식으로 (MyLib.dll을 GAC에 등록하고) <mydiag /> 섹션을 machine.config에 추가한 다음,
<?xml version="1.0" encoding="utf-8" ?>
<configuration>
<configSections>
<section name="mydiag" type="My.Diagnostics, MyLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089"/>
</configSections>
<mydiag>
</mydiag>
</configuration>
제거 시에는 단순히 MyLib.dll만 GAC에 해제하고 machine.config의 내용을 그대로 남겨 두었을 수 있습니다. (어쨌든, 가정뿐인 상황이라서 ^^; 정확한 사례를 짚어낼 수가 없군요.)
[이 글에 대해서 여러분들과 의견을 공유하고 싶습니다. 틀리거나 미흡한 부분 또는 의문 사항이 있으시면 언제든 댓글 남겨주십시오.]