search

microsoft / SqlNexus

SQL Nexus is a tool that helps you identify the root cause of SQL Server performance issues. It loads and analyzes performance data collected by SQL LogScout, SQLDiag or PSSDiag. It can dramatically reduce the amount of time you spend manually analyzing data.
MIT License
348 stars 99 forks source link

XEL READER ERROR: Unable to obtain first event in file. The file was opened but appears to be damaged or empty. #207

Closed cucmecfy closed 11 months ago

cucmecfy commented 1 year ago

Readtrace a SQL Server trace processing utility.Version 9.04.0098 built for x64.

Microsoft SQL Server 2016 (SP2-CU17) (KB5001092) - 13.0.5888.11 (X64) Mar 19 2021 19:41:38 Copyright (c) Microsoft Corporation Enterprise Edition: Core-based Licensing (64-bit) on Windows Server 2016 Datacenter 10.0 (Build 14393: )

12/19/22 14:38:17.639 [0X00004444] INFO: Starting build of XEL sequence order index 12/19/22 14:38:17.647 [0X00004754] XEL READER ERROR: Unable to obtain first event in file. The file was opened but appears to be damaged or empty. 12/19/22 14:38:17.647 [0X000043E0] XEL READER ERROR: Unable to obtain first event in file. The file was opened but appears to be damaged or empty. 12/19/22 14:38:17.647 [0X00001E5C] XEL READER ERROR: Unable to obtain first event in file. The file was opened but appears to be damaged or empty. 12/19/22 14:38:17.647 [0X00004444] XEL READER ERROR: Unable to obtain first event in file. The file was opened but appears to be damaged or empty. 12/19/22 14:38:17.647 [0X00004754] XEL READER ERROR: Attempt to open file D:\test\output failed, see previous error(s) for more details. 12/19/22 14:38:17.647 [0X000043E0] XEL READER ERROR: Attempt to open file D:\test\output failed, see previous error(s) for more details. 12/19/22 14:38:17.648 [0X00001E5C] XEL READER ERROR: Attempt to open file D:\test\output failed, see previous error(s) for more details. 12/19/22 14:38:17.650 [0X00004444] XEL READER ERROR: Attempt to open file D:\test\output failed, see previous error(s) for more details. 12/19/22 14:38:17.653 [0X00004754] ERROR: Attempt to open D:\test\output failed. 12/19/22 14:38:17.653 [0X000043E0] ERROR: Attempt to open D:\test\output failed. 12/19/22 14:38:17.654 [0X00001E5C] ERROR: Attempt to open D:\test\output failed. 12/19/22 14:38:17.654 [0X00004444] ERROR: Attempt to open D:\test\output failed. 12/19/22 14:38:17.655 [0X00004754] WARN: D:\test\output does not appear as if the events contain event_sequence, you may have to consider trace flag 260 to process this trace. 12/19/22 14:38:17.655 [0X000043E0] WARN: D:\test\output does not appear as if the events contain event_sequence, you may have to consider trace flag 260 to process this trace. 12/19/22 14:38:17.656 [0X00001E5C] WARN: D:\test\output does not appear as if the events contain event_sequence, you may have to consider trace flag 260 to process this trace. 12/19/22 14:38:17.656 [0X00004444] WARN: D:\test\output does not appear as if the events contain event_sequence, you may have to consider trace flag 260 to process this trace. 12/19/22 14:38:17.659 [0X00004444] INFO: Indexing Progress: 0 (Rate: 0/sec) 12/19/22 14:38:17.660 [0X00004444] INFO: Total events indexed: 0 (Rate: 0/sec) 12/19/22 14:38:17.661 [0X00004444] ERROR: Attempt to determine list of .XEL files failed. 12/19/22 14:38:17.662 [0X00004444] * ERROR: Attempt to initialize trace file reader failed with operating system error 0x80070006 (The handle is invalid) 12/19/22 14:38:17.730 [0X00004444] Reads completed - Global Error Status 0xfffffffe 12/19/22 14:38:17.730 [0X00004444] Signaling worker threads to complete final actions. 12/19/22 14:38:17.733 [0X00004444] Waiting for the worker threads to complete final actions. 12/19/22 14:38:17.735 [0X00004444] Performing general cleanup actions. 12/19/22 14:38:17.739 [0X00004444] Total Events Processed: 0 12/19/22 14:38:17.743 [0X00004444] Total Events Filtered: 0 12/19/22 14:38:17.746 [0X00004444] ============================================== 12/19/22 14:38:17.748 [0X00004444] WARNING: A significant portion of the events where filtered. 12/19/22 14:38:17.750 [0X00004444] You may want to check the filtering criteria. 12/19/22 14:38:17.752 [0X00004444] ============================================== 12/19/22 14:38:17.754 [0X00004444] *****

image

sqlnexus import pssdiag's output, and encountered this problem ?

suresh-kandoth commented 1 year ago

Do you have the event_sequence action captured in the XEL files? Try opening them in the SSMS Extended Event file viewer and check if event_sequence is present in all events. If not, then try using -T260 as additional parameter to ReadTrace to allow the processing. You can add this parameter to the other parameters that are printed in the ReadTrace log file.

suresh-kandoth commented 1 year ago

Are you able to process individual files?

cucmecfy commented 1 year ago

Are you able to process individual files?

I execute pssdiag'，and generate output files，include many xel files，then sqlnexus import output directory，report two error： 1、 image see sqlnexus log，found error “A column length received from the BCP client that is not valid for colid 17” 2、xel files import failed，see readtrace log，found the following error：“ XEL READER ERROR: Unable to obtain first event in file. The file was opened but appears to be damaged or empty. 12/19/22 14:38:17.647 [0X000043E0] XEL READER ERROR: Unable to obtain first event in file. The file was opened but appears to be damaged or empty. 12/19/22 14:38:17.647 [0X00001E5C] XEL READER ERROR: Unable to obtain first event in file. The file was opened but appears to be damaged or empty. 12/19/22 14:38:17.647 [0X00004444] XEL READER ERROR: Unable to obtain first event in file. The file was opened but appears to be damaged or empty. 12/19/22 14:38:17.647 [0X00004754] XEL READER ERROR: Attempt to open file D:\test\output failed, see previous error(s) for more details. 12/19/22 14:38:17.647 [0X000043E0] XEL READER ERROR: Attempt to open file D:\test\output failed, see previous error(s) for more details. 12/19/22 14:38:17.648 [0X00001E5C] XEL READER ERROR: Attempt to open file D:\test\output failed, see previous error(s) for more details. 12/19/22 14:38:17.650 [0X00004444] XEL READER ERROR: Attempt to open file D:\test\output failed, see previous error(s) for more”

how to add "-T260" parameter in sqlnexus whem import output files?

suresh-kandoth commented 1 year ago

SQL Nexus invokes ReadTrace.exe and passes the following inputs to process the *.XEL files. The binary is located usually in the folder "C:\Program Files\Microsoft Corporation\RMLUtils\"

In SQL Nexus, you can open the ReadTrace log and observe the parameters it is passing. For example, it will look like this:

12/19/22 14:24:56.789 [0X000068D0] -S 12/19/22 14:24:56.790 [0X000068D0] -d 12/19/22 14:24:56.790 [0X000068D0] -E 12/19/22 14:24:56.790 [0X000068D0] -T18 12/19/22 14:24:56.790 [0X000068D0] -T28 12/19/22 14:24:56.790 [0X000068D0] -T29 12/19/22 14:24:56.790 [0X000068D0] -I 12/19/22 14:24:56.790 [0X000068D0] -f 12/19/22 14:24:56.790 [0X000068D0] -o 12/19/22 14:24:56.791 [0X000068D0] -H!PSSDIAG

You can use those same parameters and launch ReadTrace.exe manually. See the syntax here: https://learn.microsoft.com/en-us/troubleshoot/sql/tools/replay-markup-language-utility#a-using-readtraceexe-to-import-xevent-data-in-a-database

At the end you can add -T260.

Another thing we noticed is that the last two .XEL files in that screenshot have size less than 500 MB. You can try moving those files out to another directory and see if that resolves the problem.

PiJoCoder commented 11 months ago

Closing... Please reopen if still questions.