Skip to content

Commit 7467312

Browse files
authored
Oracle Stored Procedure Fixes (open-telemetry#46466)
<!--Ex. Fixing a bug - Describe the bug and how this fixes the issue. Ex. Adding a feature - Explain what this achieves.--> #### Description Fixes Oracle Stored Procedure bugs as described in the issue <!-- Issue number (e.g. open-telemetry#1234) or full URL to issue, if applicable. --> #### Link to tracking issue Fixes open-telemetry#46438
1 parent 402147a commit 7467312

4 files changed

Lines changed: 202 additions & 7 deletions

File tree

Lines changed: 30 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,30 @@
1+
# Use this changelog template to create an entry for release notes.
2+
3+
# One of 'breaking', 'deprecation', 'new_component', 'enhancement', 'bug_fix'
4+
change_type: bug_fix
5+
6+
# The name of the component, or a single word describing the area of concern, (e.g. receiver/filelog)
7+
component: receiver/oracledb
8+
9+
# A brief description of the change. Surround your text with quotes ("") if it needs to start with a backtick (`).
10+
note: Fix stored procedure name showing as "." and top queries appearing with zero execution count
11+
12+
# Mandatory: One or more tracking issues related to the change. You can use the PR number here if no issue exists.
13+
issues: [46438]
14+
15+
# (Optional) One or more lines of additional information to render under the primary note.
16+
# These lines will be padded with 2 spaces and then inserted directly into the document.
17+
# Use pipe (|) for multiline entries.
18+
subtext: |
19+
Fixed procedure name concatenation in top query SQL to return NULL instead of "." when
20+
no stored procedure is associated with a query. Also changed top query filtering to only
21+
emit queries where the execution count has increased, preventing entries with zero count.
22+
23+
# If your change doesn't affect end users or the exported elements of any package,
24+
# you should instead start your pull request title with [chore] or use the "Skip Changelog" label.
25+
# Optional: The change log or logs in which this entry should be included.
26+
# e.g. '[user]' or '[user, api]'
27+
# Include 'user' if the change is relevant to end users.
28+
# Include 'api' if there is a change to a library API.
29+
# Default: '[user]'
30+
change_logs: [user]

receiver/oracledbreceiver/scraper.go

Lines changed: 3 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -611,24 +611,21 @@ func (s *oracleScraper) collectTopNMetricData(ctx context.Context, logs plog.Log
611611
objectType: row[objectTypeAttr],
612612
}
613613

614-
// it is possible we get a record with all deltas equal to zero. we don't want to process it any further
615-
var possiblePurge, positiveDelta bool
614+
var possiblePurge bool
616615
for _, columnName := range metricNames {
617616
delta := newCacheVal[columnName] - oldCacheVal[columnName]
618617

619618
// if any of the deltas is less than zero, cursor was likely purged from the shared pool
620619
if delta < 0 {
621620
possiblePurge = true
622621
break
623-
} else if delta > 0 {
624-
positiveDelta = true
625622
}
626623

627624
hit.metrics[columnName] = delta
628625
}
629626

630-
// skip if possible purge or all the deltas are equal to zero
631-
if !possiblePurge && positiveDelta {
627+
// skip if possible purge or no new executions since last scrape
628+
if !possiblePurge && hit.metrics[queryExecutionMetric] > 0 {
632629
hits = append(hits, hit)
633630
} else {
634631
discardedHits++

receiver/oracledbreceiver/scraper_test.go

Lines changed: 168 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -430,6 +430,174 @@ func TestGetInstanceId(t *testing.T) {
430430
assert.Equal(t, "unknown:1521", localInstanceID)
431431
}
432432

433+
func TestTopNLogsDiscardedWhenExecutionCountUnchanged(t *testing.T) {
434+
var metricRowData []metricRow
435+
var logRowData []metricRow
436+
437+
// Cache value with same EXECUTIONS as mock data (300413) but different other metrics.
438+
// This simulates: execution count unchanged, but other metrics have positive deltas.
439+
cacheValueSameExecCount := map[string]int64{
440+
"APPLICATION_WAIT_TIME": 0,
441+
"BUFFER_GETS": 3808197,
442+
"CLUSTER_WAIT_TIME": 1000,
443+
"CONCURRENCY_WAIT_TIME": 20,
444+
"CPU_TIME": 29821063,
445+
"DIRECT_READS": 3,
446+
"DIRECT_WRITES": 6,
447+
"DISK_READS": 12,
448+
"ELAPSED_TIME": 38172810,
449+
"EXECUTIONS": 300413, // same as mock data — delta will be 0
450+
"PHYSICAL_READ_BYTES": 300,
451+
"PHYSICAL_READ_REQUESTS": 100,
452+
"PHYSICAL_WRITE_BYTES": 12,
453+
"PHYSICAL_WRITE_REQUESTS": 120,
454+
"ROWS_PROCESSED": 200413,
455+
"USER_IO_WAIT_TIME": 200,
456+
}
457+
458+
logsCfg := metadata.DefaultLogsBuilderConfig()
459+
logsCfg.ResourceAttributes.HostName.Enabled = true
460+
logsCfg.Events.DbServerTopQuery.Enabled = true
461+
metricsCfg := metadata.DefaultMetricsBuilderConfig()
462+
lruCache, _ := lru.New[string, map[string]int64](500)
463+
lruCache.Add("fxk8aq3nds8aw:0", cacheValueSameExecCount)
464+
465+
scrpr := oracleScraper{
466+
logger: zap.NewNop(),
467+
mb: metadata.NewMetricsBuilder(metricsCfg, receivertest.NewNopSettings(metadata.Type)),
468+
lb: metadata.NewLogsBuilder(logsCfg, receivertest.NewNopSettings(metadata.Type)),
469+
dbProviderFunc: func() (*sql.DB, error) {
470+
return nil, nil
471+
},
472+
clientProviderFunc: func(_ *sql.DB, s string, _ *zap.Logger) dbClient {
473+
if strings.Contains(s, "V$SQL_PLAN") {
474+
metricRowFile := readFile("oracleQueryPlanData.txt")
475+
_ = json.Unmarshal(metricRowFile, &logRowData)
476+
return &fakeDbClient{Responses: [][]metricRow{logRowData}}
477+
}
478+
metricRowFile := readFile("oracleQueryMetricsData.txt")
479+
_ = json.Unmarshal(metricRowFile, &metricRowData)
480+
return &fakeDbClient{Responses: [][]metricRow{metricRowData}}
481+
},
482+
id: component.ID{},
483+
metricsBuilderConfig: metadata.DefaultMetricsBuilderConfig(),
484+
logsBuilderConfig: metadata.DefaultLogsBuilderConfig(),
485+
metricCache: lruCache,
486+
topQueryCollectCfg: TopQueryCollection{MaxQuerySampleCount: 5000, TopQueryCount: 200},
487+
instanceName: "oraclehost:1521/ORCL",
488+
hostName: "oraclehost:1521",
489+
obfuscator: newObfuscator(),
490+
serviceInstanceID: getInstanceID("oraclehost:1521/ORCL", zap.NewNop()),
491+
}
492+
493+
scrpr.logsBuilderConfig.Events.DbServerTopQuery.Enabled = true
494+
495+
err := scrpr.start(t.Context(), componenttest.NewNopHost())
496+
defer func() {
497+
assert.NoError(t, scrpr.shutdown(t.Context()))
498+
}()
499+
require.NoError(t, err)
500+
501+
logs, err := scrpr.scrapeLogs(t.Context())
502+
require.NoError(t, err)
503+
// No top query records should be emitted when execution count delta is zero
504+
assert.Equal(t, 0, logs.ResourceLogs().Len(), "No top query logs should be emitted when execution count has not increased")
505+
}
506+
507+
func TestTopNLogsProcedureNameEmpty(t *testing.T) {
508+
metricsData := []metricRow{
509+
{
510+
"APPLICATION_WAIT_TIME": "0", "BUFFER_GETS": "4000000", "CHILD_ADDRESS": "ADDR1",
511+
"CHILD_NUMBER": "0", "CLUSTER_WAIT_TIME": "0", "CONCURRENCY_WAIT_TIME": "0",
512+
"CPU_TIME": "40000000", "DIRECT_READS": "0", "DIRECT_WRITES": "0", "DISK_READS": "0",
513+
"ELAPSED_TIME": "50000000", "EXECUTIONS": "500", "PHYSICAL_READ_BYTES": "0",
514+
"PHYSICAL_READ_REQUESTS": "0", "PHYSICAL_WRITE_BYTES": "0", "PHYSICAL_WRITE_REQUESTS": "0",
515+
"ROWS_PROCESSED": "500", "SQL_FULLTEXT": "SELECT 1 FROM DUAL",
516+
"SQL_ID": "abc123", "USER_IO_WAIT_TIME": "0",
517+
"PROGRAM_ID": "", "PROCEDURE_NAME": "", "PROCEDURE_TYPE": "",
518+
},
519+
{
520+
"APPLICATION_WAIT_TIME": "0", "BUFFER_GETS": "5000000", "CHILD_ADDRESS": "ADDR2",
521+
"CHILD_NUMBER": "0", "CLUSTER_WAIT_TIME": "0", "CONCURRENCY_WAIT_TIME": "0",
522+
"CPU_TIME": "50000000", "DIRECT_READS": "0", "DIRECT_WRITES": "0", "DISK_READS": "0",
523+
"ELAPSED_TIME": "60000000", "EXECUTIONS": "600", "PHYSICAL_READ_BYTES": "0",
524+
"PHYSICAL_READ_REQUESTS": "0", "PHYSICAL_WRITE_BYTES": "0", "PHYSICAL_WRITE_REQUESTS": "0",
525+
"ROWS_PROCESSED": "600", "SQL_FULLTEXT": "SELECT * FROM ADMIN.EMP",
526+
"SQL_ID": "def456", "USER_IO_WAIT_TIME": "0",
527+
"PROGRAM_ID": "98765", "PROCEDURE_NAME": "ADMIN.MY_PROC", "PROCEDURE_TYPE": "PROCEDURE",
528+
},
529+
}
530+
531+
planData := []metricRow{}
532+
533+
logsCfg := metadata.DefaultLogsBuilderConfig()
534+
logsCfg.ResourceAttributes.HostName.Enabled = true
535+
logsCfg.Events.DbServerTopQuery.Enabled = true
536+
metricsCfg := metadata.DefaultMetricsBuilderConfig()
537+
538+
lruCache, _ := lru.New[string, map[string]int64](500)
539+
lruCache.Add("abc123:0", map[string]int64{
540+
"APPLICATION_WAIT_TIME": 0, "BUFFER_GETS": 3000000, "CLUSTER_WAIT_TIME": 0,
541+
"CONCURRENCY_WAIT_TIME": 0, "CPU_TIME": 30000000, "DIRECT_READS": 0, "DIRECT_WRITES": 0,
542+
"DISK_READS": 0, "ELAPSED_TIME": 40000000, "EXECUTIONS": 400, "PHYSICAL_READ_BYTES": 0,
543+
"PHYSICAL_READ_REQUESTS": 0, "PHYSICAL_WRITE_BYTES": 0, "PHYSICAL_WRITE_REQUESTS": 0,
544+
"ROWS_PROCESSED": 400, "USER_IO_WAIT_TIME": 0,
545+
})
546+
lruCache.Add("def456:0", map[string]int64{
547+
"APPLICATION_WAIT_TIME": 0, "BUFFER_GETS": 4000000, "CLUSTER_WAIT_TIME": 0,
548+
"CONCURRENCY_WAIT_TIME": 0, "CPU_TIME": 40000000, "DIRECT_READS": 0, "DIRECT_WRITES": 0,
549+
"DISK_READS": 0, "ELAPSED_TIME": 50000000, "EXECUTIONS": 500, "PHYSICAL_READ_BYTES": 0,
550+
"PHYSICAL_READ_REQUESTS": 0, "PHYSICAL_WRITE_BYTES": 0, "PHYSICAL_WRITE_REQUESTS": 0,
551+
"ROWS_PROCESSED": 500, "USER_IO_WAIT_TIME": 0,
552+
})
553+
554+
scrpr := oracleScraper{
555+
logger: zap.NewNop(),
556+
mb: metadata.NewMetricsBuilder(metricsCfg, receivertest.NewNopSettings(metadata.Type)),
557+
lb: metadata.NewLogsBuilder(logsCfg, receivertest.NewNopSettings(metadata.Type)),
558+
dbProviderFunc: func() (*sql.DB, error) {
559+
return nil, nil
560+
},
561+
clientProviderFunc: func(_ *sql.DB, s string, _ *zap.Logger) dbClient {
562+
if strings.Contains(s, "V$SQL_PLAN") {
563+
return &fakeDbClient{Responses: [][]metricRow{planData}}
564+
}
565+
return &fakeDbClient{Responses: [][]metricRow{metricsData}}
566+
},
567+
id: component.ID{},
568+
metricsBuilderConfig: metadata.DefaultMetricsBuilderConfig(),
569+
logsBuilderConfig: metadata.DefaultLogsBuilderConfig(),
570+
metricCache: lruCache,
571+
topQueryCollectCfg: TopQueryCollection{MaxQuerySampleCount: 5000, TopQueryCount: 200},
572+
instanceName: "oraclehost:1521/ORCL",
573+
hostName: "oraclehost:1521",
574+
obfuscator: newObfuscator(),
575+
serviceInstanceID: getInstanceID("oraclehost:1521/ORCL", zap.NewNop()),
576+
}
577+
578+
scrpr.logsBuilderConfig.Events.DbServerTopQuery.Enabled = true
579+
580+
err := scrpr.start(t.Context(), componenttest.NewNopHost())
581+
defer func() {
582+
assert.NoError(t, scrpr.shutdown(t.Context()))
583+
}()
584+
require.NoError(t, err)
585+
586+
logs, err := scrpr.scrapeLogs(t.Context())
587+
require.NoError(t, err)
588+
require.Positive(t, logs.ResourceLogs().Len())
589+
590+
scopeLogs := logs.ResourceLogs().At(0).ScopeLogs().At(0)
591+
require.Equal(t, 2, scopeLogs.LogRecords().Len(), "Expected 2 top query records")
592+
593+
for i := range scopeLogs.LogRecords().Len() {
594+
lr := scopeLogs.LogRecords().At(i)
595+
procName, _ := lr.Attributes().Get("oracledb.procedure_name")
596+
assert.NotEqual(t, ".", procName.Str(),
597+
"Procedure name must not be '.' — should be empty or a valid name (record %d)", i)
598+
}
599+
}
600+
433601
func TestScrapesTopNLogsOnlyWhenIntervalHasElapsed(t *testing.T) {
434602
var metricRowData []metricRow
435603
var logRowData []metricRow

receiver/oracledbreceiver/templates/oracleQueryMetricsAndTextSql.tmpl

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -21,7 +21,7 @@
2121
S.DIRECT_READS,
2222
S.PROGRAM_ID,
2323
P.OBJECT_TYPE AS PROCEDURE_TYPE,
24-
P.OWNER || '.' || P.OBJECT_NAME AS PROCEDURE_NAME
24+
CASE WHEN P.OBJECT_ID IS NOT NULL THEN P.OWNER || '.' || P.OBJECT_NAME END AS PROCEDURE_NAME
2525
FROM
2626
V$SQL S
2727
LEFT JOIN (

0 commit comments

Comments
 (0)