debug logs everywhere

This commit is contained in:
Shreyas Goenka 2025-03-05 16:21:14 +01:00
parent f227862d89
commit d80a5ec673
No known key found for this signature in database
GPG Key ID: 92A07DF49CCB0622
22 changed files with 149 additions and 259 deletions

View File

@ -99,3 +99,4 @@
< } pid=12345 mutator=validate:files_to_sync sdk=true
10:07:59 Debug: Path /Workspace/Users/[USERNAME]/.bundle/debug/default/files has type directory (ID: 0) pid=12345 mutator=validate:files_to_sync
10:07:59 Info: completed execution pid=12345 exit_code=0
10:07:59 Debug: no telemetry logs to upload pid=12345

View File

@ -1,51 +0,0 @@
{
"headers": {
"Authorization": [
"Bearer [DATABRICKS_TOKEN]"
]
},
"method": "POST",
"path": "/telemetry-ext",
"body": {
"uploadTime": "UNIX_TIME_MILLIS",
"items": [],
"protoLogs": [
"{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"execution_context\":{\"cmd_exec_id\":\"[UUID]\",\"version\":\"[DEV_VERSION]\",\"command\":\"selftest_send-telemetry\",\"operating_system\":\"[OS]\"},\"cli_test_event\":{\"name\":\"VALUE1\"}}}}",
"{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"execution_context\":{\"cmd_exec_id\":\"[UUID]\",\"version\":\"[DEV_VERSION]\",\"command\":\"selftest_send-telemetry\",\"operating_system\":\"[OS]\"},\"cli_test_event\":{\"name\":\"VALUE2\"}}}}"
]
}
}
{
"headers": {
"Authorization": [
"Bearer [DATABRICKS_TOKEN]"
]
},
"method": "POST",
"path": "/telemetry-ext",
"body": {
"uploadTime": "UNIX_TIME_MILLIS",
"items": [],
"protoLogs": [
"{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"execution_context\":{\"cmd_exec_id\":\"[UUID]\",\"version\":\"[DEV_VERSION]\",\"command\":\"selftest_send-telemetry\",\"operating_system\":\"[OS]\"},\"cli_test_event\":{\"name\":\"VALUE1\"}}}}",
"{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"execution_context\":{\"cmd_exec_id\":\"[UUID]\",\"version\":\"[DEV_VERSION]\",\"command\":\"selftest_send-telemetry\",\"operating_system\":\"[OS]\"},\"cli_test_event\":{\"name\":\"VALUE2\"}}}}"
]
}
}
{
"headers": {
"Authorization": [
"Bearer [DATABRICKS_TOKEN]"
]
},
"method": "POST",
"path": "/telemetry-ext",
"body": {
"uploadTime": "UNIX_TIME_MILLIS",
"items": [],
"protoLogs": [
"{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"execution_context\":{\"cmd_exec_id\":\"[UUID]\",\"version\":\"[DEV_VERSION]\",\"command\":\"selftest_send-telemetry\",\"operating_system\":\"[OS]\"},\"cli_test_event\":{\"name\":\"VALUE1\"}}}}",
"{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"execution_context\":{\"cmd_exec_id\":\"[UUID]\",\"version\":\"[DEV_VERSION]\",\"command\":\"selftest_send-telemetry\",\"operating_system\":\"[OS]\"},\"cli_test_event\":{\"name\":\"VALUE2\"}}}}"
]
}
}

View File

@ -1,56 +0,0 @@
>>> [CLI] selftest send-telemetry --debug
HH:MM:SS Info: start pid=PID version=[DEV_VERSION] args="[CLI], selftest, send-telemetry, --debug"
HH:MM:SS Info: completed execution pid=PID exit_code=0
HH:MM:SS Debug: POST /telemetry-ext
> {
> "items": null,
> "protoLogs": [
> "{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"... (210 more bytes)",
> "{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"... (210 more bytes)"
> ],
> "uploadTime": "UNIX_TIME_MILLIS"
> }
< HTTP/1.1 501 Not Implemented
< {
< "error_code": "ERROR_CODE",
< "message": "Endpoint not implemented."
< } pid=PID sdk=true
HH:MM:SS Debug: non-retriable error: Endpoint not implemented. pid=PID sdk=true
HH:MM:SS Debug: Attempt 1 failed due to a server side error. Retrying status code: 501
pid=PID
HH:MM:SS Debug: POST /telemetry-ext
> {
> "items": null,
> "protoLogs": [
> "{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"... (210 more bytes)",
> "{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"... (210 more bytes)"
> ],
> "uploadTime": "UNIX_TIME_MILLIS"
> }
< HTTP/1.1 501 Not Implemented
< {
< "error_code": "ERROR_CODE",
< "message": "Endpoint not implemented."
< } pid=PID sdk=true
HH:MM:SS Debug: non-retriable error: Endpoint not implemented. pid=PID sdk=true
HH:MM:SS Debug: Attempt 2 failed due to a server side error. Retrying status code: 501
pid=PID
HH:MM:SS Debug: POST /telemetry-ext
> {
> "items": null,
> "protoLogs": [
> "{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"... (210 more bytes)",
> "{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"... (210 more bytes)"
> ],
> "uploadTime": "UNIX_TIME_MILLIS"
> }
< HTTP/1.1 501 Not Implemented
< {
< "error_code": "ERROR_CODE",
< "message": "Endpoint not implemented."
< } pid=PID sdk=true
HH:MM:SS Debug: non-retriable error: Endpoint not implemented. pid=PID sdk=true
HH:MM:SS Debug: Attempt 3 failed due to a server side error. Retrying status code: 501
pid=PID
HH:MM:SS Debug: failed to upload telemetry: failed to upload telemetry logs after three attempts pid=PID

View File

@ -1 +0,0 @@
trace $CLI selftest send-telemetry --debug

View File

@ -1,17 +0,0 @@
[[Server]]
Pattern = "POST /telemetry-ext"
Response.Body = '''
{
"error_code": "ERROR_CODE",
"message": "Endpoint not implemented."
}
'''
Response.StatusCode = 501
[[Repls]]
Old = "(?:[01][0-9]|2[0-3]):[0-5][0-9]:[0-5][0-9]"
New = "HH:MM:SS"
[[Repls]]
Old = "pid=[0-9]+"
New = "pid=PID"

View File

@ -1,2 +1,56 @@
>>> [CLI] selftest send-telemetry
>>> [CLI] selftest send-telemetry --debug
HH:MM:SS Info: start pid=PID version=[DEV_VERSION] args="[CLI], selftest, send-telemetry, --debug"
HH:MM:SS Info: completed execution pid=PID exit_code=0
HH:MM:SS Debug: POST /telemetry-ext
> {
> "items": null,
> "protoLogs": [
> "{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"... (210 more bytes)",
> "{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"... (210 more bytes)"
> ],
> "uploadTime": "UNIX_TIME_MILLIS"
> }
< HTTP/1.1 501 Not Implemented
< {
< "error_code": "ERROR_CODE",
< "message": "Endpoint not implemented."
< } pid=PID sdk=true
HH:MM:SS Debug: non-retriable error: Endpoint not implemented. pid=PID sdk=true
HH:MM:SS Debug: Attempt 1 failed due to a server side error. Retrying status code: 501
pid=PID
HH:MM:SS Debug: POST /telemetry-ext
> {
> "items": null,
> "protoLogs": [
> "{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"... (210 more bytes)",
> "{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"... (210 more bytes)"
> ],
> "uploadTime": "UNIX_TIME_MILLIS"
> }
< HTTP/1.1 501 Not Implemented
< {
< "error_code": "ERROR_CODE",
< "message": "Endpoint not implemented."
< } pid=PID sdk=true
HH:MM:SS Debug: non-retriable error: Endpoint not implemented. pid=PID sdk=true
HH:MM:SS Debug: Attempt 2 failed due to a server side error. Retrying status code: 501
pid=PID
HH:MM:SS Debug: POST /telemetry-ext
> {
> "items": null,
> "protoLogs": [
> "{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"... (210 more bytes)",
> "{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"... (210 more bytes)"
> ],
> "uploadTime": "UNIX_TIME_MILLIS"
> }
< HTTP/1.1 501 Not Implemented
< {
< "error_code": "ERROR_CODE",
< "message": "Endpoint not implemented."
< } pid=PID sdk=true
HH:MM:SS Debug: non-retriable error: Endpoint not implemented. pid=PID sdk=true
HH:MM:SS Debug: Attempt 3 failed due to a server side error. Retrying status code: 501
pid=PID
HH:MM:SS Debug: failed to upload telemetry: failed to upload telemetry logs after three attempts pid=PID

View File

@ -1 +1 @@
trace $CLI selftest send-telemetry
trace $CLI selftest send-telemetry --debug

View File

@ -1,51 +0,0 @@
{
"headers": {
"Authorization": [
"Bearer [DATABRICKS_TOKEN]"
]
},
"method": "POST",
"path": "/telemetry-ext",
"body": {
"uploadTime": "UNIX_TIME_MILLIS",
"items": [],
"protoLogs": [
"{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"execution_context\":{\"cmd_exec_id\":\"[UUID]\",\"version\":\"[DEV_VERSION]\",\"command\":\"selftest_send-telemetry\",\"operating_system\":\"[OS]\"},\"cli_test_event\":{\"name\":\"VALUE1\"}}}}",
"{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"execution_context\":{\"cmd_exec_id\":\"[UUID]\",\"version\":\"[DEV_VERSION]\",\"command\":\"selftest_send-telemetry\",\"operating_system\":\"[OS]\"},\"cli_test_event\":{\"name\":\"VALUE2\"}}}}"
]
}
}
{
"headers": {
"Authorization": [
"Bearer [DATABRICKS_TOKEN]"
]
},
"method": "POST",
"path": "/telemetry-ext",
"body": {
"uploadTime": "UNIX_TIME_MILLIS",
"items": [],
"protoLogs": [
"{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"execution_context\":{\"cmd_exec_id\":\"[UUID]\",\"version\":\"[DEV_VERSION]\",\"command\":\"selftest_send-telemetry\",\"operating_system\":\"[OS]\"},\"cli_test_event\":{\"name\":\"VALUE1\"}}}}",
"{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"execution_context\":{\"cmd_exec_id\":\"[UUID]\",\"version\":\"[DEV_VERSION]\",\"command\":\"selftest_send-telemetry\",\"operating_system\":\"[OS]\"},\"cli_test_event\":{\"name\":\"VALUE2\"}}}}"
]
}
}
{
"headers": {
"Authorization": [
"Bearer [DATABRICKS_TOKEN]"
]
},
"method": "POST",
"path": "/telemetry-ext",
"body": {
"uploadTime": "UNIX_TIME_MILLIS",
"items": [],
"protoLogs": [
"{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"execution_context\":{\"cmd_exec_id\":\"[UUID]\",\"version\":\"[DEV_VERSION]\",\"command\":\"selftest_send-telemetry\",\"operating_system\":\"[OS]\"},\"cli_test_event\":{\"name\":\"VALUE1\"}}}}",
"{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"execution_context\":{\"cmd_exec_id\":\"[UUID]\",\"version\":\"[DEV_VERSION]\",\"command\":\"selftest_send-telemetry\",\"operating_system\":\"[OS]\"},\"cli_test_event\":{\"name\":\"VALUE2\"}}}}"
]
}
}

View File

@ -1,53 +0,0 @@
>>> [CLI] selftest send-telemetry --debug
HH:MM:SS Info: start pid=PID version=[DEV_VERSION] args="[CLI], selftest, send-telemetry, --debug"
HH:MM:SS Info: completed execution pid=PID exit_code=0
HH:MM:SS Debug: POST /telemetry-ext
> {
> "items": null,
> "protoLogs": [
> "{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"... (210 more bytes)",
> "{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"... (210 more bytes)"
> ],
> "uploadTime": "UNIX_TIME_MILLIS"
> }
< HTTP/1.1 200 OK
< {
< "errors": null,
< "numProtoSuccess": 1
< } pid=PID sdk=true
HH:MM:SS Debug: Attempt 1 was a partial success. Number of logs uploaded: 1 out of 2
pid=PID
HH:MM:SS Debug: POST /telemetry-ext
> {
> "items": null,
> "protoLogs": [
> "{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"... (210 more bytes)",
> "{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"... (210 more bytes)"
> ],
> "uploadTime": "UNIX_TIME_MILLIS"
> }
< HTTP/1.1 200 OK
< {
< "errors": null,
< "numProtoSuccess": 1
< } pid=PID sdk=true
HH:MM:SS Debug: Attempt 2 was a partial success. Number of logs uploaded: 1 out of 2
pid=PID
HH:MM:SS Debug: POST /telemetry-ext
> {
> "items": null,
> "protoLogs": [
> "{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"... (210 more bytes)",
> "{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"... (210 more bytes)"
> ],
> "uploadTime": "UNIX_TIME_MILLIS"
> }
< HTTP/1.1 200 OK
< {
< "errors": null,
< "numProtoSuccess": 1
< } pid=PID sdk=true
HH:MM:SS Debug: Attempt 3 was a partial success. Number of logs uploaded: 1 out of 2
pid=PID
HH:MM:SS Debug: failed to upload telemetry: failed to upload telemetry logs after three attempts pid=PID

View File

@ -1 +0,0 @@
trace $CLI selftest send-telemetry --debug

View File

@ -1,17 +0,0 @@
[[Server]]
Pattern = "POST /telemetry-ext"
Response.Body = '''
{
"errors": [],
"numProtoSuccess": 1
}
'''
[[Repls]]
Old = "(?:[01][0-9]|2[0-3]):[0-5][0-9]:[0-5][0-9]"
New = "HH:MM:SS"
[[Repls]]
Old = "pid=[0-9]+"
New = "pid=PID"

View File

@ -1,2 +1,53 @@
>>> [CLI] selftest send-telemetry
>>> [CLI] selftest send-telemetry --debug
HH:MM:SS Info: start pid=PID version=[DEV_VERSION] args="[CLI], selftest, send-telemetry, --debug"
HH:MM:SS Info: completed execution pid=PID exit_code=0
HH:MM:SS Debug: POST /telemetry-ext
> {
> "items": null,
> "protoLogs": [
> "{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"... (210 more bytes)",
> "{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"... (210 more bytes)"
> ],
> "uploadTime": "UNIX_TIME_MILLIS"
> }
< HTTP/1.1 200 OK
< {
< "errors": null,
< "numProtoSuccess": 1
< } pid=PID sdk=true
HH:MM:SS Debug: Attempt 1 was a partial success. Number of logs uploaded: 1 out of 2
pid=PID
HH:MM:SS Debug: POST /telemetry-ext
> {
> "items": null,
> "protoLogs": [
> "{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"... (210 more bytes)",
> "{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"... (210 more bytes)"
> ],
> "uploadTime": "UNIX_TIME_MILLIS"
> }
< HTTP/1.1 200 OK
< {
< "errors": null,
< "numProtoSuccess": 1
< } pid=PID sdk=true
HH:MM:SS Debug: Attempt 2 was a partial success. Number of logs uploaded: 1 out of 2
pid=PID
HH:MM:SS Debug: POST /telemetry-ext
> {
> "items": null,
> "protoLogs": [
> "{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"... (210 more bytes)",
> "{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"... (210 more bytes)"
> ],
> "uploadTime": "UNIX_TIME_MILLIS"
> }
< HTTP/1.1 200 OK
< {
< "errors": null,
< "numProtoSuccess": 1
< } pid=PID sdk=true
HH:MM:SS Debug: Attempt 3 was a partial success. Number of logs uploaded: 1 out of 2
pid=PID
HH:MM:SS Debug: failed to upload telemetry: failed to upload telemetry logs after three attempts pid=PID

View File

@ -1 +1 @@
trace $CLI selftest send-telemetry
trace $CLI selftest send-telemetry --debug

View File

@ -1,2 +1,5 @@
>>> [CLI] selftest send-telemetry
>>> [CLI] selftest send-telemetry --debug
HH:MM:SS Info: start pid=PID version=[DEV_VERSION] args="[CLI], selftest, send-telemetry, --debug"
HH:MM:SS Info: completed execution pid=PID exit_code=0
HH:MM:SS Debug: telemetry upload is disabled. Not uploading any logs. pid=PID

View File

@ -1,3 +1,3 @@
export DATABRICKS_CLI_DISABLE_TELEMETRY="true"
trace $CLI selftest send-telemetry
trace $CLI selftest send-telemetry --debug

View File

@ -1,2 +1,19 @@
>>> [CLI] selftest send-telemetry
>>> [CLI] selftest send-telemetry --debug
HH:MM:SS Info: start pid=PID version=[DEV_VERSION] args="[CLI], selftest, send-telemetry, --debug"
HH:MM:SS Info: completed execution pid=PID exit_code=0
HH:MM:SS Debug: POST /telemetry-ext
> {
> "items": null,
> "protoLogs": [
> "{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"... (210 more bytes)",
> "{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"... (210 more bytes)"
> ],
> "uploadTime": "UNIX_TIME_MILLIS"
> }
< HTTP/1.1 200 OK
< {
< "errors": null,
< "numProtoSuccess": 2
< } pid=PID sdk=true
HH:MM:SS Debug: All 2 logs uploaded successfully pid=PID

View File

@ -1 +1 @@
trace $CLI selftest send-telemetry
trace $CLI selftest send-telemetry --debug

View File

@ -24,3 +24,11 @@ Response.Body = '''
"numProtoSuccess": 2
}
'''
[[Repls]]
Old = "(?:[01][0-9]|2[0-3]):[0-5][0-9]:[0-5][0-9]"
New = "HH:MM:SS"
[[Repls]]
Old = "pid=[0-9]+"
New = "pid=PID"

View File

@ -10,8 +10,8 @@
"uploadTime": "UNIX_TIME_MILLIS",
"items": [],
"protoLogs": [
"{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"execution_context\":{\"cmd_exec_id\":\"[UUID]\",\"version\":\"[DEV_VERSION]\",\"command\":\"selftest_send-telemetry\",\"operating_system\":\"[OS]\",\"execution_time_ms\":1},\"cli_test_event\":{\"name\":\"VALUE1\"}}}}",
"{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"execution_context\":{\"cmd_exec_id\":\"[UUID]\",\"version\":\"[DEV_VERSION]\",\"command\":\"selftest_send-telemetry\",\"operating_system\":\"[OS]\",\"execution_time_ms\":1},\"cli_test_event\":{\"name\":\"VALUE2\"}}}}"
"{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"execution_context\":{\"cmd_exec_id\":\"[UUID]\",\"version\":\"[DEV_VERSION]\",\"command\":\"selftest_send-telemetry\",\"operating_system\":\"[OS]\"},\"cli_test_event\":{\"name\":\"VALUE1\"}}}}",
"{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"execution_context\":{\"cmd_exec_id\":\"[UUID]\",\"version\":\"[DEV_VERSION]\",\"command\":\"selftest_send-telemetry\",\"operating_system\":\"[OS]\"},\"cli_test_event\":{\"name\":\"VALUE2\"}}}}"
]
}
}

View File

@ -6,8 +6,8 @@ HH:MM:SS Debug: POST /telemetry-ext
> {
> "items": null,
> "protoLogs": [
> "{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"... (232 more bytes)",
> "{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"... (232 more bytes)"
> "{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"... (210 more bytes)",
> "{\"frontend_log_event_id\":\"[UUID]\",\"entry\":{\"databricks_cli_log\":{\"... (210 more bytes)"
> ],
> "uploadTime": "UNIX_TIME_MILLIS"
> }

View File

@ -173,11 +173,13 @@ Stack Trace:
func uploadTelemetry(ctx context.Context, cmdStr string, startTime time.Time, exitCode int) {
// Return early if there are no logs to upload.
if !telemetry.HasLogs(ctx) {
log.Debugf(ctx, "no telemetry logs to upload")
return
}
// Telemetry is disabled. We don't upload logs.
if os.Getenv(telemetry.DisableEnvVar) != "" {
log.Debugf(ctx, "telemetry upload is disabled. Not uploading any logs.")
return
}

View File

@ -94,6 +94,7 @@ func Upload(ctx context.Context, cfg *config.Config) error {
// All logs were uploaded successfully.
if err == nil && resp.NumProtoSuccess >= int64(len(protoLogs)) {
log.Debugf(ctx, "All %d logs uploaded successfully", len(protoLogs))
return nil
}