Skip to content

Commit 7f1e8eb

Browse files
jeffqjiangNewNikhil-Nunna
jeffqjiangNew
authored and
Nikhil-Nunna
committed
[rocDecode] Add core function entry and exit logs. (#3851)
## Motivation This PR adds entry and exit logs for core functions. ## Technical Details - Info level (3) logs are added at core function entry and exit points. - Monotonic clock stamp, process id, thread id, and file name are added to the logs. - The logs now have similar format to HIP logs for better viewing when both are present. - Direct error or warning logs to std::cerr. Other logs still go to std::cout. ## JIRA ID <!-- If applicable, mention the JIRA ID resolved by this PR (Example: Resolves SWDEV-12345). --> <!-- Do not post any JIRA links here. --> ## Test Plan Set env variable ROCDEC_LOG_LEVEL to control log output. All CTests and conformance tests must pass. Example summary of the test results: - CTests:       Start  1: video_decodeRaw-HEVC  1/15 Test  #1: video_decodeRaw-HEVC .............   Passed    2.05 sec       Start  2: video_decodeRaw-AVC  2/15 Test  #2: video_decodeRaw-AVC ..............   Passed    1.89 sec       Start  3: video_decodeRaw-AV1  3/15 Test  #3: video_decodeRaw-AV1 ..............   Passed    2.31 sec       Start  4: video_decodeRaw-VP9  4/15 Test  #4: video_decodeRaw-VP9 ..............   Passed    2.04 sec       Start  5: rocdec_Decode-HEVC  5/15 Test  #5: rocdec_Decode-HEVC ...............   Passed    0.92 sec       Start  6: rocDecode_Negative_API_Tests  6/15 Test  #6: rocDecode_Negative_API_Tests .....   Passed    0.78 sec       Start  7: video_decode-HEVC  7/15 Test  #7: video_decode-HEVC ................   Passed    2.74 sec       Start  8: video_decode-AVC  8/15 Test  #8: video_decode-AVC .................   Passed    2.64 sec       Start  9: video_decode-AV1  9/15 Test  #9: video_decode-AV1 .................   Passed    2.74 sec       Start 10: video_decode-VP9 10/15 Test #10: video_decode-VP9 .................   Passed    2.78 sec       Start 11: video_decodePerf-HEVC 11/15 Test #11: video_decodePerf-HEVC ............   Passed    2.92 sec       Start 12: video_decodeBatch 12/15 Test #12: video_decodeBatch ................   Passed    4.34 sec       Start 13: video_decodeRGB-HEVC 13/15 Test #13: video_decodeRGB-HEVC .............   Passed   33.51 sec       Start 14: video_decodeMem-HEVC 14/15 Test #14: video_decodeMem-HEVC .............   Passed    2.09 sec       Start 15: video_decodeRGB-Resize 15/15 Test #15: video_decodeRGB-Resize ...........   Passed   33.94 sec 100% tests passed, 0 tests failed out of 15 - AVC conformance test: Conformance test completed on the 127 streams: - The number of passing streams is 127 - The number of failing streams is 0 - The number of streams that did not finish decoding is 0 - HEVC conformance test: Conformance test completed on the 135 streams: - The number of passing streams is 135 - The number of failing streams is 0 - The number of streams that did not finish decoding is 0 - AV1 conformance test: Conformance test completed on the 162 streams: - The number of passing streams is 162 - The number of failing streams is 0 - The number of streams that did not finish decoding is 0 - VP9 conformance test: Conformance test completed on the 108 streams: - The number of passing streams is 108 - The number of failing streams is 0 - The number of streams that did not finish decoding is 0 ## Test Result Function entry/exit logs should show up when ROCDEC_LOG_LEVEL >= 3. All conformance tests should pass. ## Submission Checklist - [ ] Look over the contributing guidelines at https://github.com/ROCm/ROCm/blob/develop/CONTRIBUTING.md#pull-requests.
1 parent b37bd57 commit 7f1e8eb

19 files changed

+609
-129
lines changed

‎projects/rocdecode/CHANGELOG.md‎

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -2,6 +2,12 @@
22

33
Full documentation for rocDecode is available at [https://rocm.docs.amd.com/projects/rocDecode/en/latest/](https://rocm.docs.amd.com/projects/rocDecode/en/latest/)
44

5+
## (Unreleased) rocDecode 1.7.1
6+
7+
### Added
8+
9+
* Logging improvement: Added function entry and exit logs (at Info log level).
10+
511
## rocDecode 1.7.0 for ROCm 7.2.1
612

713
### Changed

‎projects/rocdecode/CMakeLists.txt‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -47,7 +47,7 @@ if (NOT DEFINED CMAKE_CXX_COMPILER)
4747
endif()
4848

4949
# rocdecode Version
50-
set(VERSION "1.7.0")
50+
set(VERSION "1.7.1")
5151

5252
# Set Project Version and Language
5353
project(rocdecode VERSION ${VERSION} LANGUAGES CXX)

‎projects/rocdecode/docs/reference/rocDecode-logging-control.rst‎

Lines changed: 5 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -12,11 +12,11 @@ The log level can be changed by either setting the log level through the ``ROCDE
1212

1313
The logging levels are:
1414

15-
| 0: Critical (Default level)
16-
| 1: Error
17-
| 2: Warning
18-
| 3: Info
19-
| 4: Debug
15+
| 0: Critical (Default level, Only output critical messages)
16+
| 1: Error (Output critical and error messages)
17+
| 2: Warning (Output critical, error and warning messages)
18+
| 3: Info (Output critical, error, warning and info messages)
19+
| 4: Debug (Output critical, error, warning, info and debug messages)
2020
2121
The log level defines the maximum severity of log messages to output. For example, to output warning and error messages as well as critical messages, ``ROCDEC_LOG_LEVEL`` would need to be set to 2:
2222

‎projects/rocdecode/src/bit_stream_reader/es_reader.cpp‎

Lines changed: 68 additions & 20 deletions
Original file line numberDiff line numberDiff line change
@@ -63,25 +63,20 @@ RocVideoESParser::~RocVideoESParser() {
6363
}
6464
}
6565

66-
int RocVideoESParser::GetDataSizeInRB() {
67-
if (read_ptr_ == write_ptr_) {
68-
return 0;
69-
} else if (read_ptr_ < write_ptr_) {
70-
return write_ptr_ - read_ptr_;
71-
} else {
72-
return BS_RING_SIZE - read_ptr_ + write_ptr_;
73-
}
66+
uint32_t RocVideoESParser::GetDataSizeInRB() {
67+
return (read_ptr_ <= write_ptr_) ? (write_ptr_ - read_ptr_) : (BS_RING_SIZE - read_ptr_ + write_ptr_);
7468
}
7569

76-
int RocVideoESParser::FetchBitStream()
77-
{
70+
int RocVideoESParser::FetchBitStream() {
71+
FunctionEntryLog(logger_);
7872
int free_space;
7973
int read_size;
8074
int total_read_size = 0;
8175

8276
// A full ring has BS_RING_SIZE - 1 bytes
8377
free_space = BS_RING_SIZE - 1 - GetDataSizeInRB();
8478
if (free_space == 0) {
79+
FunctionExitLog(logger_);
8580
return 0;
8681
}
8782

@@ -97,10 +92,12 @@ int RocVideoESParser::FetchBitStream()
9792
}
9893
total_read_size += read_size;
9994
if (end_of_file_) {
95+
FunctionExitLog(logger_);
10096
return total_read_size;
10197
}
10298
free_space -= read_size;
10399
if (free_space == 0) {
100+
FunctionExitLog(logger_);
104101
return total_read_size;
105102
}
106103
}
@@ -116,6 +113,7 @@ int RocVideoESParser::FetchBitStream()
116113
}
117114
total_read_size += read_size;
118115
}
116+
FunctionExitLog(logger_);
119117
return total_read_size;
120118
}
121119

@@ -158,6 +156,7 @@ void RocVideoESParser::SetReadPointer(int value) {
158156
}
159157

160158
bool RocVideoESParser::FindStartCode() {
159+
FunctionEntryLog(logger_);
161160
uint8_t three_bytes[3];
162161
int i;
163162

@@ -190,6 +189,7 @@ bool RocVideoESParser::FindStartCode() {
190189
}
191190
curr_byte_offset_ = (curr_byte_offset_ + 1) % BS_RING_SIZE;
192191
}
192+
FunctionExitLog(logger_);
193193
return num_start_code_ ? true : false;
194194
}
195195

@@ -280,6 +280,7 @@ void RocVideoESParser::CheckAvcNalForSlice(int start_code_offset, int *slice_fla
280280
}
281281

282282
int RocVideoESParser::GetPicDataAvcHevc(uint8_t **p_pic_data, int *pic_size) {
283+
FunctionEntryLog(logger_);
283284
int slice_nal_flag;
284285
int first_slice_flag = 0;
285286
int num_slices = 0;
@@ -337,17 +338,20 @@ int RocVideoESParser::GetPicDataAvcHevc(uint8_t **p_pic_data, int *pic_size) {
337338
} else {
338339
*pic_size = 0;
339340
}
341+
FunctionExitLog(logger_);
340342
return 0;
341343
}
342344

343345
bool RocVideoESParser::ReadObuHeaderAndSize(int *obu_type) {
346+
FunctionEntryLog(logger_);
344347
uint8_t header_byte;
345348
int obu_extension_flag;
346349

347350
obu_size_ = 0;
348351
obu_byte_offset_ = curr_byte_offset_;
349352
// Parser header
350353
if (GetByte(curr_byte_offset_, &header_byte) == false) {
354+
FunctionExitLog(logger_);
351355
return false;
352356
}
353357
*obu_type = (header_byte >> 3) & 0x0F;
@@ -364,6 +368,7 @@ bool RocVideoESParser::ReadObuHeaderAndSize(int *obu_type) {
364368
uint8_t data_byte;
365369
for (len = 0; len < 8; ++len) {
366370
if (GetByte(curr_byte_offset_ + len, &data_byte) == false) {
371+
FunctionExitLog(logger_);
367372
return false;
368373
}
369374
value |= (data_byte & 0x7F) << (len * 7);
@@ -375,6 +380,7 @@ bool RocVideoESParser::ReadObuHeaderAndSize(int *obu_type) {
375380
obu_size_ += len + value;
376381
curr_byte_offset_ = (curr_byte_offset_ + len + value) % BS_RING_SIZE;
377382

383+
FunctionExitLog(logger_);
378384
return true;
379385
}
380386

@@ -404,6 +410,7 @@ bool RocVideoESParser::CopyObuFromRing() {
404410
}
405411

406412
int RocVideoESParser::GetPicDataAv1(uint8_t **p_pic_data, int *pic_size) {
413+
FunctionEntryLog(logger_);
407414
int obu_type;
408415
pic_data_size_ = 0;
409416

@@ -423,10 +430,12 @@ int RocVideoESParser::GetPicDataAv1(uint8_t **p_pic_data, int *pic_size) {
423430
*p_pic_data = pic_data_.data();
424431
*pic_size = pic_data_size_;
425432
num_temp_units_++;
433+
FunctionExitLog(logger_);
426434
return 0;
427435
}
428436

429437
int RocVideoESParser::GetPicDataIvf(uint8_t **p_pic_data, int *pic_size) {
438+
FunctionEntryLog(logger_);
430439
uint8_t frame_header[12];
431440
pic_data_size_ = 0;
432441
if (ReadBytes(curr_byte_offset_, 12, frame_header)) {
@@ -444,17 +453,26 @@ int RocVideoESParser::GetPicDataIvf(uint8_t **p_pic_data, int *pic_size) {
444453
}
445454
*p_pic_data = pic_data_.data();
446455
*pic_size = pic_data_size_;
456+
FunctionExitLog(logger_);
447457
return 0;
448458
}
449459

450460
int RocVideoESParser::GetPicData(uint8_t **p_pic_data, int *pic_size, int64_t *pts) {
461+
FunctionEntryLog(logger_);
451462
*pts = 0;
463+
int ret;
452464
switch (stream_type_) {
453465
case kStreamTypeAvcElementary:
454-
case kStreamTypeHevcElementary:
455-
return GetPicDataAvcHevc(p_pic_data, pic_size);
456-
case kStreamTypeAv1Elementary:
457-
return GetPicDataAv1(p_pic_data, pic_size);
466+
case kStreamTypeHevcElementary: {
467+
ret = GetPicDataAvcHevc(p_pic_data, pic_size);
468+
FunctionExitLog(logger_);
469+
return ret;
470+
}
471+
case kStreamTypeAv1Elementary: {
472+
ret = GetPicDataAv1(p_pic_data, pic_size);
473+
FunctionExitLog(logger_);
474+
return ret;
475+
}
458476
case kStreamTypeAv1Ivf:
459477
case kStreamTypeVp9Ivf: {
460478
if (!ivf_file_header_read_) {
@@ -464,33 +482,46 @@ int RocVideoESParser::GetPicData(uint8_t **p_pic_data, int *pic_size, int64_t *p
464482
SetReadPointer(curr_byte_offset_);
465483
ivf_file_header_read_ = true;
466484
}
467-
return GetPicDataIvf(p_pic_data, pic_size);
485+
ret = GetPicDataIvf(p_pic_data, pic_size);
486+
FunctionExitLog(logger_);
487+
return ret;
468488
}
469489
default: {
470490
*p_pic_data = pic_data_.data();
471491
*pic_size = 0;
492+
FunctionExitLog(logger_);
472493
return 0;
473494
}
474495
}
475496
}
476497

477498
rocDecVideoCodec RocVideoESParser::GetCodecId() {
499+
FunctionEntryLog(logger_);
500+
rocDecVideoCodec codec;
478501
switch (stream_type_) {
479502
case kStreamTypeAvcElementary:
480-
return rocDecVideoCodec_AVC;
503+
codec = rocDecVideoCodec_AVC;
504+
break;
481505
case kStreamTypeHevcElementary:
482-
return rocDecVideoCodec_HEVC;
506+
codec = rocDecVideoCodec_HEVC;
507+
break;
483508
case kStreamTypeAv1Elementary:
484509
case kStreamTypeAv1Ivf:
485-
return rocDecVideoCodec_AV1;
510+
codec = rocDecVideoCodec_AV1;
511+
break;
486512
case kStreamTypeVp9Ivf:
487-
return rocDecVideoCodec_VP9;
513+
codec = rocDecVideoCodec_VP9;
514+
break;
488515
default:
489-
return rocDecVideoCodec_NumCodecs;
516+
codec = rocDecVideoCodec_NumCodecs;
517+
break;
490518
}
519+
FunctionExitLog(logger_);
520+
return codec;
491521
}
492522

493523
int RocVideoESParser::ProbeStreamType() {
524+
FunctionEntryLog(logger_);
494525
int stream_type = kStreamTypeUnsupported;
495526
int stream_type_score = 0;
496527
uint8_t *stream_buf;
@@ -557,10 +588,12 @@ int RocVideoESParser::ProbeStreamType() {
557588
free(stream_buf);
558589
}
559590
p_stream_file_.seekg(0, std::ios::beg);
591+
FunctionExitLog(logger_);
560592
return stream_type;
561593
}
562594

563595
int RocVideoESParser::CheckAvcEStream(uint8_t *p_stream, int stream_size) {
596+
FunctionEntryLog(logger_);
564597
int score = 0;
565598
int curr_offset = 0;
566599
int num_start_codes = 0;
@@ -656,10 +689,12 @@ int RocVideoESParser::CheckAvcEStream(uint8_t *p_stream, int stream_size) {
656689
} else {
657690
score = sps_present * 25 + pps_present * 25 + idr_slice_present * 20 + slice_present * 15 + first_slice_present * 15;
658691
}
692+
FunctionExitLog(logger_);
659693
return score;
660694
}
661695

662696
int RocVideoESParser::CheckHevcEStream(uint8_t *p_stream, int stream_size) {
697+
FunctionEntryLog(logger_);
663698
int score = 0;
664699
int curr_offset = 0;
665700
int num_start_codes = 0;
@@ -800,12 +835,15 @@ int RocVideoESParser::CheckHevcEStream(uint8_t *p_stream, int stream_size) {
800835
} else {
801836
score = vps_present * 15 + sps_present * 20 + pps_present * 20 + rap_slice_present * 15 + slice_present * 15 + first_slice_present * 15;
802837
}
838+
FunctionExitLog(logger_);
803839
return score;
804840
}
805841

806842
int RocVideoESParser::EbspToRbsp(uint8_t *streamBuffer, int begin_bytepos, int end_bytepos) {
843+
FunctionEntryLog(logger_);
807844
int count = 0;
808845
if (end_bytepos < begin_bytepos) {
846+
FunctionExitLog(logger_);
809847
return end_bytepos;
810848
}
811849
uint8_t *streamBuffer_i = streamBuffer + begin_bytepos;
@@ -819,6 +857,7 @@ int RocVideoESParser::EbspToRbsp(uint8_t *streamBuffer, int begin_bytepos, int e
819857
if (tmp == 0x03) {
820858
//check the 4th uint8_t after 0x000003, except when cabac_zero_word is used, in which case the last three bytes of this NAL unit must be 0x000003
821859
if ((streamBuffer_i + 1 != streamBuffer_end) && (streamBuffer_i[1] > 0x03)) {
860+
FunctionExitLog(logger_);
822861
return -1;
823862
}
824863
//if cabac_zero_word is used, the final uint8_t of this NAL unit(0x03) is discarded, and the last two bytes of RBSP must be 0x0000
@@ -840,6 +879,7 @@ int RocVideoESParser::EbspToRbsp(uint8_t *streamBuffer, int begin_bytepos, int e
840879
}
841880
streamBuffer_i++;
842881
}
882+
FunctionExitLog(logger_);
843883
return end_bytepos - begin_bytepos + reduce_count;
844884
}
845885

@@ -858,6 +898,7 @@ uint32_t RocVideoESParser::ReadUVLC(const uint8_t *p_stream, size_t &bit_offset)
858898
}
859899

860900
int RocVideoESParser::CheckAv1EStream(uint8_t *p_stream, int stream_size) {
901+
FunctionEntryLog(logger_);
861902
int score = 0;
862903
uint8_t *obu_stream = p_stream;
863904
uint32_t curr_offset = 0;
@@ -1092,10 +1133,12 @@ int RocVideoESParser::CheckAv1EStream(uint8_t *p_stream, int stream_size) {
10921133
} else {
10931134
score = temporal_delimiter_obu_present * 25 + seq_header_obu_present * 25 + frame_obu_present * 50 + (frame_header_obu_present & tile_group_obu_present) * 50;
10941135
}
1136+
FunctionExitLog(logger_);
10951137
return score;
10961138
}
10971139

10981140
int RocVideoESParser::CheckIvfAv1Stream(uint8_t *p_stream, int stream_size) {
1141+
FunctionEntryLog(logger_);
10991142
static const char *IVF_SIGNATURE = "DKIF";
11001143
static const char *AV1_FourCC = "AV01";
11011144
static const int IvfFileHeaderSize = 32;
@@ -1127,10 +1170,12 @@ int RocVideoESParser::CheckIvfAv1Stream(uint8_t *p_stream, int stream_size) {
11271170
} else {
11281171
score = 0;
11291172
}
1173+
FunctionExitLog(logger_);
11301174
return score;
11311175
}
11321176

11331177
int RocVideoESParser::CheckVp9EStream(uint8_t *p_stream, int stream_size) {
1178+
FunctionEntryLog(logger_);
11341179
int score = 0;
11351180
size_t offset = 0; // bit offset
11361181
Vp9UncompressedHeader uncomp_header;
@@ -1172,10 +1217,12 @@ int RocVideoESParser::CheckVp9EStream(uint8_t *p_stream, int stream_size) {
11721217
} else {
11731218
return 0;
11741219
}
1220+
FunctionExitLog(logger_);
11751221
return score;
11761222
}
11771223

11781224
int RocVideoESParser::CheckIvfVp9Stream(uint8_t *p_stream, int stream_size) {
1225+
FunctionEntryLog(logger_);
11791226
static const char *IVF_SIGNATURE = "DKIF";
11801227
static const char *VP9_FourCC = "VP90";
11811228
static const int IvfFileHeaderSize = 32;
@@ -1207,5 +1254,6 @@ int RocVideoESParser::CheckIvfVp9Stream(uint8_t *p_stream, int stream_size) {
12071254
} else {
12081255
score = 0;
12091256
}
1257+
FunctionExitLog(logger_);
12101258
return score;
12111259
}

‎projects/rocdecode/src/bit_stream_reader/es_reader.h‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -129,7 +129,7 @@ class RocVideoESParser {
129129
/*! \brief Function to check the remaining data size in the ring buffer
130130
* \return Number of bytes still available in the ring
131131
*/
132-
int GetDataSizeInRB();
132+
uint32_t GetDataSizeInRB();
133133

134134
/*! \brief Function to read one byte from the ring buffer without advancing the read pointer
135135
* \param [in] offset The byte offset to read

0 commit comments

Comments
 (0)