feat(csharp/src/Drivers/Apache): tracing - work-in-progress #5

birschick-bq · 2024-11-07T19:35:20Z

POC

Assumptions

Use tracing instead of logging as tracing allows cross-reference to other activities in other logs.
The number of activities will not be large enough to to motivate using ILogger instead.

CSharp

In csharp, using System.Diagnostics.DiagnosticSource package employing as it is the suggested way to enable OpenTelemetry compatible tracing.

ActivitySource
ActivityListener
Activity
ActivityEvent
Tags

Intent is to allow the passing of the "parent" span and trace id to the AdbcStatement using TraceParent, SetOption or in the TraceActivity overloads. The Execute* API methods will populate the parent context if the option is set.

Sample output:

Successful activity (multiple calls to `ExecuteUpdateAsync`)

{"Status":"Ok","HasRemoteParent":false,"Kind":"Client","OperationName":"Apache.Arrow.Adbc.Drivers.Apache.Spark.SparkHttpConnection.CreateProtocolAsync","Duration":"00:00:00.0007402","StartTimeUtc":"2024-12-05T01:33:55.3308199Z","Id":"00-378ae9f2eba536c93346af74fdff5686-fadcf9aa07aabb13-01","ParentId":"00-378ae9f2eba536c93346af74fdff5686-e88acabdd36c2097-01","RootId":"378ae9f2eba536c93346af74fdff5686","TraceStateString":null,"SpanId":"fadcf9aa07aabb13","TraceId":"378ae9f2eba536c93346af74fdff5686","Recorded":true,"IsAllDataRequested":true,"ActivityTraceFlags":"Recorded","ParentSpanId":"e88acabdd36c2097","IdFormat":"W3C","TagObjects":[{"Key":"transport.type","Value":"ThriftHttpTransport"}],"Events":[],"Links":[],"Baggage":[]}
{"Status":"Ok","HasRemoteParent":false,"Kind":"Client","OperationName":"Apache.Arrow.Adbc.Drivers.Apache.Hive2.HiveServer2Connection.OpenAsync","Duration":"00:00:00.6007097","StartTimeUtc":"2024-12-05T01:33:55.323202Z","Id":"00-378ae9f2eba536c93346af74fdff5686-e88acabdd36c2097-01","ParentId":null,"RootId":"378ae9f2eba536c93346af74fdff5686","TraceStateString":null,"SpanId":"e88acabdd36c2097","TraceId":"378ae9f2eba536c93346af74fdff5686","Recorded":true,"IsAllDataRequested":true,"ActivityTraceFlags":"Recorded","ParentSpanId":"0000000000000000","IdFormat":"W3C","TagObjects":[],"Events":[{"Name":"openSession.start","Timestamp":"2024-12-05T01:33:55.3626004+00:00","Tags":[]},{"Name":"openSession.end","Timestamp":"2024-12-05T01:33:55.9233582+00:00","Tags":[{"Key":"openSession.statusCode","Value":"SUCCESS_STATUS"}]}],"Links":[],"Baggage":[]}
{"Status":"Ok","HasRemoteParent":false,"Kind":"Client","OperationName":"Apache.Arrow.Adbc.Drivers.Apache.Hive2.HiveServer2Statement.ExecuteStatementAsync","Duration":"00:00:01.5304733","StartTimeUtc":"2024-12-05T01:33:55.9289546Z","Id":"00-9fb183c1e445ca3bf24ae120d338ac09-34bbd0424aeceb88-01","ParentId":"00-9fb183c1e445ca3bf24ae120d338ac09-e78ff1fd7dfa203f-01","RootId":"9fb183c1e445ca3bf24ae120d338ac09","TraceStateString":null,"SpanId":"34bbd0424aeceb88","TraceId":"9fb183c1e445ca3bf24ae120d338ac09","Recorded":true,"IsAllDataRequested":true,"ActivityTraceFlags":"Recorded","ParentSpanId":"e78ff1fd7dfa203f","IdFormat":"W3C","TagObjects":[],"Events":[],"Links":[],"Baggage":[]}
{"Status":"Ok","HasRemoteParent":false,"Kind":"Client","OperationName":"Apache.Arrow.Adbc.Drivers.Apache.Hive2.HiveServer2Connection.PollForResponseAsync","Duration":"00:00:00.2631094","StartTimeUtc":"2024-12-05T01:33:57.4622893Z","Id":"00-9fb183c1e445ca3bf24ae120d338ac09-c56da90e44862562-01","ParentId":"00-9fb183c1e445ca3bf24ae120d338ac09-e78ff1fd7dfa203f-01","RootId":"9fb183c1e445ca3bf24ae120d338ac09","TraceStateString":null,"SpanId":"c56da90e44862562","TraceId":"9fb183c1e445ca3bf24ae120d338ac09","Recorded":true,"IsAllDataRequested":true,"ActivityTraceFlags":"Recorded","ParentSpanId":"e78ff1fd7dfa203f","IdFormat":"W3C","TagObjects":[],"Events":[{"Name":"getOperationStatus.start","Timestamp":"2024-12-05T01:33:57.4631717+00:00","Tags":[]},{"Name":"getOperationStatus.stop","Timestamp":"2024-12-05T01:33:57.7253651+00:00","Tags":[{"Key":"statusResponse.operationState","Value":"FINISHED_STATE"}]}],"Links":[],"Baggage":[]}
{"Status":"Ok","HasRemoteParent":false,"Kind":"Client","OperationName":"Apache.Arrow.Adbc.Drivers.Apache.Hive2.HiveServer2Connection.GetResultSetMetadataAsync","Duration":"00:00:00.2861667","StartTimeUtc":"2024-12-05T01:33:57.7283265Z","Id":"00-9fb183c1e445ca3bf24ae120d338ac09-9d0921ad3659e25b-01","ParentId":"00-9fb183c1e445ca3bf24ae120d338ac09-5873916b088de557-01","RootId":"9fb183c1e445ca3bf24ae120d338ac09","TraceStateString":null,"SpanId":"9d0921ad3659e25b","TraceId":"9fb183c1e445ca3bf24ae120d338ac09","Recorded":true,"IsAllDataRequested":true,"ActivityTraceFlags":"Recorded","ParentSpanId":"5873916b088de557","IdFormat":"W3C","TagObjects":[],"Events":[],"Links":[],"Baggage":[]}
{"Status":"Ok","HasRemoteParent":false,"Kind":"Client","OperationName":"Apache.Arrow.Adbc.Drivers.Apache.Hive2.HiveServer2Statement.GetResultSetSchemaAsync","Duration":"00:00:00.2894037","StartTimeUtc":"2024-12-05T01:33:57.7270417Z","Id":"00-9fb183c1e445ca3bf24ae120d338ac09-5873916b088de557-01","ParentId":"00-9fb183c1e445ca3bf24ae120d338ac09-e78ff1fd7dfa203f-01","RootId":"9fb183c1e445ca3bf24ae120d338ac09","TraceStateString":null,"SpanId":"5873916b088de557","TraceId":"9fb183c1e445ca3bf24ae120d338ac09","Recorded":true,"IsAllDataRequested":true,"ActivityTraceFlags":"Recorded","ParentSpanId":"e78ff1fd7dfa203f","IdFormat":"W3C","TagObjects":[],"Events":[],"Links":[],"Baggage":[]}
{"Status":"Ok","HasRemoteParent":false,"Kind":"Client","OperationName":"Apache.Arrow.Adbc.Drivers.Apache.Hive2.HiveServer2Statement.ExecuteQueryAsync","Duration":"00:00:02.0893484","StartTimeUtc":"2024-12-05T01:33:55.9282404Z","Id":"00-9fb183c1e445ca3bf24ae120d338ac09-e78ff1fd7dfa203f-01","ParentId":null,"RootId":"9fb183c1e445ca3bf24ae120d338ac09","TraceStateString":null,"SpanId":"e78ff1fd7dfa203f","TraceId":"9fb183c1e445ca3bf24ae120d338ac09","Recorded":true,"IsAllDataRequested":true,"ActivityTraceFlags":"Recorded","ParentSpanId":"0000000000000000","IdFormat":"W3C","TagObjects":[],"Events":[],"Links":[],"Baggage":[]}
{"Status":"Ok","HasRemoteParent":false,"Kind":"Client","OperationName":"Apache.Arrow.Adbc.Drivers.Apache.Spark.SparkDatabricksReader.ReadNextRecordBatchAsync","Duration":"00:00:00.9589533","StartTimeUtc":"2024-12-05T01:33:58.0200167Z","Id":"00-aedd18244a95d0ccd1e120deafa3bc1b-0ec4d41fa26cd937-01","ParentId":null,"RootId":"aedd18244a95d0ccd1e120deafa3bc1b","TraceStateString":null,"SpanId":"0ec4d41fa26cd937","TraceId":"aedd18244a95d0ccd1e120deafa3bc1b","Recorded":true,"IsAllDataRequested":true,"ActivityTraceFlags":"Recorded","ParentSpanId":"0000000000000000","IdFormat":"W3C","TagObjects":[],"Events":[{"Name":"fetchResults.start","Timestamp":"2024-12-05T01:33:58.0210706+00:00","Tags":[{"Key":"batches.batchSize","Value":50000}]},{"Name":"fetchResults.end","Timestamp":"2024-12-05T01:33:58.9582793+00:00","Tags":[{"Key":"fetchResults.statusCode","Value":"SUCCESS_STATUS"},{"Key":"batches.count","Value":13},{"Key":"batches.rowCount","Value":53248}]}],"Links":[],"Baggage":[]}
{"Status":"Ok","HasRemoteParent":false,"Kind":"Client","OperationName":"Apache.Arrow.Adbc.Drivers.Apache.Spark.SparkDatabricksReader.ReadNextRecordBatchAsync","Duration":"00:00:00.0033313","StartTimeUtc":"2024-12-05T01:33:58.9845235Z","Id":"00-15cfe7bf5ec101ac364ad489cc529df2-2c6fe83fe0befe0c-01","ParentId":null,"RootId":"15cfe7bf5ec101ac364ad489cc529df2","TraceStateString":null,"SpanId":"2c6fe83fe0befe0c","TraceId":"15cfe7bf5ec101ac364ad489cc529df2","Recorded":true,"IsAllDataRequested":true,"ActivityTraceFlags":"Recorded","ParentSpanId":"0000000000000000","IdFormat":"W3C","TagObjects":[],"Events":[],"Links":[],"Baggage":[]}
{"Status":"Ok","HasRemoteParent":false,"Kind":"Client","OperationName":"Apache.Arrow.Adbc.Drivers.Apache.Spark.SparkDatabricksReader.ReadNextRecordBatchAsync","Duration":"00:00:00.0038941","StartTimeUtc":"2024-12-05T01:33:58.9884852Z","Id":"00-44dd8fd98e2e44a96a7a1a65f026ed8b-eb022475e7980833-01","ParentId":null,"RootId":"44dd8fd98e2e44a96a7a1a65f026ed8b","TraceStateString":null,"SpanId":"eb022475e7980833","TraceId":"44dd8fd98e2e44a96a7a1a65f026ed8b","Recorded":true,"IsAllDataRequested":true,"ActivityTraceFlags":"Recorded","ParentSpanId":"0000000000000000","IdFormat":"W3C","TagObjects":[],"Events":[],"Links":[],"Baggage":[]}
{"Status":"Ok","HasRemoteParent":false,"Kind":"Client","OperationName":"Apache.Arrow.Adbc.Drivers.Apache.Spark.SparkDatabricksReader.ReadNextRecordBatchAsync","Duration":"00:00:00.0017296","StartTimeUtc":"2024-12-05T01:33:58.9929581Z","Id":"00-e671f41fc4ab8488ebde26f19bae7972-29a0da09a6148d71-01","ParentId":null,"RootId":"e671f41fc4ab8488ebde26f19bae7972","TraceStateString":null,"SpanId":"29a0da09a6148d71","TraceId":"e671f41fc4ab8488ebde26f19bae7972","Recorded":true,"IsAllDataRequested":true,"ActivityTraceFlags":"Recorded","ParentSpanId":"0000000000000000","IdFormat":"W3C","TagObjects":[],"Events":[],"Links":[],"Baggage":[]}
{"Status":"Ok","HasRemoteParent":false,"Kind":"Client","OperationName":"Apache.Arrow.Adbc.Drivers.Apache.Spark.SparkDatabricksReader.ReadNextRecordBatchAsync","Duration":"00:00:00.0018298","StartTimeUtc":"2024-12-05T01:33:58.9951835Z","Id":"00-ab97c4f823413b82482fddb03777d0f8-23a92b57eb701936-01","ParentId":null,"RootId":"ab97c4f823413b82482fddb03777d0f8","TraceStateString":null,"SpanId":"23a92b57eb701936","TraceId":"ab97c4f823413b82482fddb03777d0f8","Recorded":true,"IsAllDataRequested":true,"ActivityTraceFlags":"Recorded","ParentSpanId":"0000000000000000","IdFormat":"W3C","TagObjects":[],"Events":[],"Links":[],"Baggage":[]}
{"Status":"Ok","HasRemoteParent":false,"Kind":"Client","OperationName":"Apache.Arrow.Adbc.Drivers.Apache.Spark.SparkDatabricksReader.ReadNextRecordBatchAsync","Duration":"00:00:00.0006286","StartTimeUtc":"2024-12-05T01:33:58.9975478Z","Id":"00-86d23d46533185598de68daf4ab646e1-9f4ff63701474f5f-01","ParentId":null,"RootId":"86d23d46533185598de68daf4ab646e1","TraceStateString":null,"SpanId":"9f4ff63701474f5f","TraceId":"86d23d46533185598de68daf4ab646e1","Recorded":true,"IsAllDataRequested":true,"ActivityTraceFlags":"Recorded","ParentSpanId":"0000000000000000","IdFormat":"W3C","TagObjects":[],"Events":[],"Links":[],"Baggage":[]}
{"Status":"Ok","HasRemoteParent":false,"Kind":"Client","OperationName":"Apache.Arrow.Adbc.Drivers.Apache.Spark.SparkDatabricksReader.ReadNextRecordBatchAsync","Duration":"00:00:00.0009469","StartTimeUtc":"2024-12-05T01:33:58.9986145Z","Id":"00-ea51897c461fd99923622d5bfdbeda5b-cca3bd41ad81da9b-01","ParentId":null,"RootId":"ea51897c461fd99923622d5bfdbeda5b","TraceStateString":null,"SpanId":"cca3bd41ad81da9b","TraceId":"ea51897c461fd99923622d5bfdbeda5b","Recorded":true,"IsAllDataRequested":true,"ActivityTraceFlags":"Recorded","ParentSpanId":"0000000000000000","IdFormat":"W3C","TagObjects":[],"Events":[],"Links":[],"Baggage":[]}
{"Status":"Ok","HasRemoteParent":false,"Kind":"Client","OperationName":"Apache.Arrow.Adbc.Drivers.Apache.Spark.SparkDatabricksReader.ReadNextRecordBatchAsync","Duration":"00:00:00.0010900","StartTimeUtc":"2024-12-05T01:33:59.0001204Z","Id":"00-d2505db288592106c56018c69f91bcdd-da9a88ef001e708a-01","ParentId":null,"RootId":"d2505db288592106c56018c69f91bcdd","TraceStateString":null,"SpanId":"da9a88ef001e708a","TraceId":"d2505db288592106c56018c69f91bcdd","Recorded":true,"IsAllDataRequested":true,"ActivityTraceFlags":"Recorded","ParentSpanId":"0000000000000000","IdFormat":"W3C","TagObjects":[],"Events":[],"Links":[],"Baggage":[]}
{"Status":"Ok","HasRemoteParent":false,"Kind":"Client","OperationName":"Apache.Arrow.Adbc.Drivers.Apache.Spark.SparkDatabricksReader.ReadNextRecordBatchAsync","Duration":"00:00:00.0014181","StartTimeUtc":"2024-12-05T01:33:59.00162Z","Id":"00-33df1ad109005e727fe6b39acaf664ad-7637a00678934995-01","ParentId":null,"RootId":"33df1ad109005e727fe6b39acaf664ad","TraceStateString":null,"SpanId":"7637a00678934995","TraceId":"33df1ad109005e727fe6b39acaf664ad","Recorded":true,"IsAllDataRequested":true,"ActivityTraceFlags":"Recorded","ParentSpanId":"0000000000000000","IdFormat":"W3C","TagObjects":[],"Events":[],"Links":[],"Baggage":[]}
{"Status":"Ok","HasRemoteParent":false,"Kind":"Client","OperationName":"Apache.Arrow.Adbc.Drivers.Apache.Spark.SparkDatabricksReader.ReadNextRecordBatchAsync","Duration":"00:00:00.0011099","StartTimeUtc":"2024-12-05T01:33:59.0034298Z","Id":"00-46b480f1b79523d12e1f318e9555f9a9-bd4faed531353463-01","ParentId":null,"RootId":"46b480f1b79523d12e1f318e9555f9a9","TraceStateString":null,"SpanId":"bd4faed531353463","TraceId":"46b480f1b79523d12e1f318e9555f9a9","Recorded":true,"IsAllDataRequested":true,"ActivityTraceFlags":"Recorded","ParentSpanId":"0000000000000000","IdFormat":"W3C","TagObjects":[],"Events":[],"Links":[],"Baggage":[]}
{"Status":"Ok","HasRemoteParent":false,"Kind":"Client","OperationName":"Apache.Arrow.Adbc.Drivers.Apache.Spark.SparkDatabricksReader.ReadNextRecordBatchAsync","Duration":"00:00:00.0014432","StartTimeUtc":"2024-12-05T01:33:59.0050384Z","Id":"00-6635fa1a07ee0ce1818b29376d610f1f-3dc3545de83ea8bd-01","ParentId":null,"RootId":"6635fa1a07ee0ce1818b29376d610f1f","TraceStateString":null,"SpanId":"3dc3545de83ea8bd","TraceId":"6635fa1a07ee0ce1818b29376d610f1f","Recorded":true,"IsAllDataRequested":true,"ActivityTraceFlags":"Recorded","ParentSpanId":"0000000000000000","IdFormat":"W3C","TagObjects":[],"Events":[],"Links":[],"Baggage":[]}
{"Status":"Ok","HasRemoteParent":false,"Kind":"Client","OperationName":"Apache.Arrow.Adbc.Drivers.Apache.Spark.SparkDatabricksReader.ReadNextRecordBatchAsync","Duration":"00:00:00.0009833","StartTimeUtc":"2024-12-05T01:33:59.0071456Z","Id":"00-422e05bb161e0664e8acbca8cdd78992-30ac88108ab654cc-01","ParentId":null,"RootId":"422e05bb161e0664e8acbca8cdd78992","TraceStateString":null,"SpanId":"30ac88108ab654cc","TraceId":"422e05bb161e0664e8acbca8cdd78992","Recorded":true,"IsAllDataRequested":true,"ActivityTraceFlags":"Recorded","ParentSpanId":"0000000000000000","IdFormat":"W3C","TagObjects":[],"Events":[],"Links":[],"Baggage":[]}
{"Status":"Ok","HasRemoteParent":false,"Kind":"Client","OperationName":"Apache.Arrow.Adbc.Drivers.Apache.Spark.SparkDatabricksReader.ReadNextRecordBatchAsync","Duration":"00:00:00.0011229","StartTimeUtc":"2024-12-05T01:33:59.0086254Z","Id":"00-b6ebf3f2cbcff1805276ee33e0e09968-743c2daa35f8ef1e-01","ParentId":null,"RootId":"b6ebf3f2cbcff1805276ee33e0e09968","TraceStateString":null,"SpanId":"743c2daa35f8ef1e","TraceId":"b6ebf3f2cbcff1805276ee33e0e09968","Recorded":true,"IsAllDataRequested":true,"ActivityTraceFlags":"Recorded","ParentSpanId":"0000000000000000","IdFormat":"W3C","TagObjects":[],"Events":[],"Links":[],"Baggage":[]}
{"Status":"Ok","HasRemoteParent":false,"Kind":"Client","OperationName":"Apache.Arrow.Adbc.Drivers.Apache.Spark.SparkDatabricksReader.ReadNextRecordBatchAsync","Duration":"00:00:00.2999797","StartTimeUtc":"2024-12-05T01:33:59.0101634Z","Id":"00-d3904f076d35e18c52786ddf9794d81a-0d908b641879f8b4-01","ParentId":null,"RootId":"d3904f076d35e18c52786ddf9794d81a","TraceStateString":null,"SpanId":"0d908b641879f8b4","TraceId":"d3904f076d35e18c52786ddf9794d81a","Recorded":true,"IsAllDataRequested":true,"ActivityTraceFlags":"Recorded","ParentSpanId":"0000000000000000","IdFormat":"W3C","TagObjects":[],"Events":[{"Name":"fetchResults.start","Timestamp":"2024-12-05T01:33:59.0102079+00:00","Tags":[{"Key":"batches.batchSize","Value":50000}]},{"Name":"fetchResults.end","Timestamp":"2024-12-05T01:33:59.3088936+00:00","Tags":[{"Key":"fetchResults.statusCode","Value":"SUCCESS_STATUS"},{"Key":"batches.count","Value":1},{"Key":"batches.rowCount","Value":1500}]}],"Links":[],"Baggage":[]}
{"Status":"Ok","HasRemoteParent":false,"Kind":"Client","OperationName":"Apache.Arrow.Adbc.Drivers.Apache.Spark.SparkDatabricksReader.ReadNextRecordBatchAsync","Duration":"00:00:00.0000418","StartTimeUtc":"2024-12-05T01:33:59.3111101Z","Id":"00-4701ffbf1e8fcce1ddcc507a47e1e17c-03b598d5cbb5ceb0-01","ParentId":null,"RootId":"4701ffbf1e8fcce1ddcc507a47e1e17c","TraceStateString":null,"SpanId":"03b598d5cbb5ceb0","TraceId":"4701ffbf1e8fcce1ddcc507a47e1e17c","Recorded":true,"IsAllDataRequested":true,"ActivityTraceFlags":"Recorded","ParentSpanId":"0000000000000000","IdFormat":"W3C","TagObjects":[],"Events":[],"Links":[],"Baggage":[]}

Exception activity

{"Status":"Ok","HasRemoteParent":false,"Kind":"Client","OperationName":"Apache.Arrow.Adbc.Drivers.Apache.Spark.SparkHttpConnection.CreateProtocolAsync","Duration":"00:00:00.0007649","StartTimeUtc":"2024-12-05T01:34:41.7607389Z","Id":"00-00c8ee8157d8359771e066fa581a0ade-defe33b649112507-01","ParentId":"00-00c8ee8157d8359771e066fa581a0ade-ff05390d82845e10-01","RootId":"00c8ee8157d8359771e066fa581a0ade","TraceStateString":null,"SpanId":"defe33b649112507","TraceId":"00c8ee8157d8359771e066fa581a0ade","Recorded":true,"IsAllDataRequested":true,"ActivityTraceFlags":"Recorded","ParentSpanId":"ff05390d82845e10","IdFormat":"W3C","TagObjects":[{"Key":"transport.type","Value":"ThriftHttpTransport"}],"Events":[],"Links":[],"Baggage":[]}
{"Status":"Error","HasRemoteParent":false,"Kind":"Client","OperationName":"Apache.Arrow.Adbc.Drivers.Apache.Hive2.HiveServer2Connection.OpenAsync","Duration":"00:00:00.1438477","StartTimeUtc":"2024-12-05T01:34:41.7529542Z","Id":"00-00c8ee8157d8359771e066fa581a0ade-ff05390d82845e10-01","ParentId":null,"RootId":"00c8ee8157d8359771e066fa581a0ade","TraceStateString":null,"SpanId":"ff05390d82845e10","TraceId":"00c8ee8157d8359771e066fa581a0ade","Recorded":true,"IsAllDataRequested":true,"ActivityTraceFlags":"Recorded","ParentSpanId":"0000000000000000","IdFormat":"W3C","TagObjects":[],"Events":[{"Name":"openSession.start","Timestamp":"2024-12-05T01:34:41.7931176+00:00","Tags":[]},{"Name":"exception","Timestamp":"2024-12-05T01:34:41.8962506+00:00","Tags":[{"Key":"exception.message","Value":"Couldn\u0027t connect to server: System.Net.Http.HttpRequestException: No such host is known. (unknownhost.azure.com:80)\r\n ---\u003E System.Net.Sockets.SocketException (11001): No such host is known.\r\n   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.ThrowException(SocketError error, CancellationToken cancellationToken)\r\n   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.System.Threading.Tasks.Sources.IValueTaskSource.GetResult(Int16 token)\r\n   at System.Net.Sockets.Socket.\u003CConnectAsync\u003Eg__WaitForConnectWithCancellation|285_0(AwaitableSocketAsyncEventArgs saea, ValueTask connectTask, CancellationToken cancellationToken)\r\n   at System.Net.Http.HttpConnectionPool.ConnectToTcpHostAsync(String host, Int32 port, HttpRequestMessage initialRequest, Boolean async, CancellationToken cancellationToken)\r\n   --- End of inner exception stack trace ---\r\n   at System.Net.Http.HttpConnectionPool.ConnectToTcpHostAsync(String host, Int32 port, HttpRequestMessage initialRequest, Boolean async, CancellationToken cancellationToken)\r\n   at System.Net.Http.HttpConnectionPool.ConnectAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)\r\n   at System.Net.Http.HttpConnectionPool.CreateHttp11ConnectionAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)\r\n   at System.Net.Http.HttpConnectionPool.AddHttp11ConnectionAsync(QueueItem queueItem)\r\n   at System.Threading.Tasks.TaskCompletionSourceWithCancellation\u00601.WaitWithCancellationAsync(CancellationToken cancellationToken)\r\n   at System.Net.Http.HttpConnectionPool.SendWithVersionDetectionAndRetryAsync(HttpRequestMessage request, Boolean async, Boolean doRequestAuth, CancellationToken cancellationToken)\r\n   at System.Net.Http.DiagnosticsHandler.SendAsyncCore(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)\r\n   at System.Net.Http.RedirectHandler.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)\r\n   at System.Net.Http.HttpClient.\u003CSendAsync\u003Eg__Core|83_0(HttpRequestMessage request, HttpCompletionOption completionOption, CancellationTokenSource cts, Boolean disposeCts, CancellationTokenSource pendingRequestsCts, CancellationToken originalCancellationToken)\r\n   at Thrift.Transport.Client.THttpTransport.FlushAsync(CancellationToken cancellationToken)"},{"Key":"exception.stacktrace","Value":"Thrift.Transport.TTransportException: Couldn\u0027t connect to server: System.Net.Http.HttpRequestException: No such host is known. (unknownhost.azure.com:80)\r\n ---\u003E System.Net.Sockets.SocketException (11001): No such host is known.\r\n   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.ThrowException(SocketError error, CancellationToken cancellationToken)\r\n   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.System.Threading.Tasks.Sources.IValueTaskSource.GetResult(Int16 token)\r\n   at System.Net.Sockets.Socket.\u003CConnectAsync\u003Eg__WaitForConnectWithCancellation|285_0(AwaitableSocketAsyncEventArgs saea, ValueTask connectTask, CancellationToken cancellationToken)\r\n   at System.Net.Http.HttpConnectionPool.ConnectToTcpHostAsync(String host, Int32 port, HttpRequestMessage initialRequest, Boolean async, CancellationToken cancellationToken)\r\n   --- End of inner exception stack trace ---\r\n   at System.Net.Http.HttpConnectionPool.ConnectToTcpHostAsync(String host, Int32 port, HttpRequestMessage initialRequest, Boolean async, CancellationToken cancellationToken)\r\n   at System.Net.Http.HttpConnectionPool.ConnectAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)\r\n   at System.Net.Http.HttpConnectionPool.CreateHttp11ConnectionAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)\r\n   at System.Net.Http.HttpConnectionPool.AddHttp11ConnectionAsync(QueueItem queueItem)\r\n   at System.Threading.Tasks.TaskCompletionSourceWithCancellation\u00601.WaitWithCancellationAsync(CancellationToken cancellationToken)\r\n   at System.Net.Http.HttpConnectionPool.SendWithVersionDetectionAndRetryAsync(HttpRequestMessage request, Boolean async, Boolean doRequestAuth, CancellationToken cancellationToken)\r\n   at System.Net.Http.DiagnosticsHandler.SendAsyncCore(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)\r\n   at System.Net.Http.RedirectHandler.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)\r\n   at System.Net.Http.HttpClient.\u003CSendAsync\u003Eg__Core|83_0(HttpRequestMessage request, HttpCompletionOption completionOption, CancellationTokenSource cts, Boolean disposeCts, CancellationTokenSource pendingRequestsCts, CancellationToken originalCancellationToken)\r\n   at Thrift.Transport.Client.THttpTransport.FlushAsync(CancellationToken cancellationToken)\r\n   at Thrift.Transport.Client.THttpTransport.FlushAsync(CancellationToken cancellationToken)\r\n   at Apache.Hive.Service.Rpc.Thrift.TCLIService.Client.send_OpenSession(TOpenSessionReq req, CancellationToken cancellationToken) in C:\\repos\\birschick-bq\\arrow-adbc\\csharp\\src\\Drivers\\Apache\\Thrift\\Service\\Rpc\\Thrift\\TCLIService.cs:line 120\r\n   at Apache.Hive.Service.Rpc.Thrift.TCLIService.Client.OpenSession(TOpenSessionReq req, CancellationToken cancellationToken) in C:\\repos\\birschick-bq\\arrow-adbc\\csharp\\src\\Drivers\\Apache\\Thrift\\Service\\Rpc\\Thrift\\TCLIService.cs:line 106\r\n   at Apache.Arrow.Adbc.Drivers.Apache.Hive2.HiveServer2Connection.\u003COpenAsync\u003Eb__17_0(Activity activity) in C:\\repos\\birschick-bq\\arrow-adbc\\csharp\\src\\Drivers\\Apache\\Hive2\\HiveServer2Connection.cs:line 79\r\n   at Apache.Arrow.Adbc.Tracing.TracingBase.TraceActivityAsync(Func\u00602 call, String activityName, String traceParent) in C:\\repos\\birschick-bq\\arrow-adbc\\csharp\\src\\Apache.Arrow.Adbc\\Tracing\\TracingBase.cs:line 136"},{"Key":"exception.type","Value":"Thrift.Transport.TTransportException"}]}],"Links":[],"Baggage":[]}

Instrumentation

Note: The "zero-code" instrumentation did not seem to behave as expected.
Intention is to add an TraceActivity in each significant method (see OpenAsync, for example)
If an interactive step is contained in the method, add ActivityEvent before and after its execution.
The TraceActivity overloads handles thrown exceptions to trace the exception and then rethrow the exception.

Exporting

To export traces, clients can use the OpenTelemetry model. This is implemented in HiveServer2Connection

TracerProvider tracerProvider = Sdk.CreateTracerProviderBuilder()
    .AddSource(ActivitySource.Name)
    .AddAdbcFileExporter(ActivitySource.Name, tracingDirectory?.FullName)
    .Build();

Missing Features

Handling of obfuscating of all potential PII, by default.

davidhcoe · 2024-11-11T14:56:35Z

For this first iteration, is the thought how to establish a framework for the C# drivers to implement?

I was thinking it was targeting the higher-level classes like AdbcConnection so that any of the drivers, including the ones used via Interop, would have the same base logging.

…to inherit

csharp/src/Drivers/Apache/Apache.Arrow.Adbc.Drivers.Apache.csproj

…ort for AdbcConnection11 and AdbcStatement11

csharp/src/Apache.Arrow.Adbc/Tracing/TracingConnectionImpl.cs

csharp/src/Drivers/Apache/Hive2/HiveServer2Connection.cs

…ize and number of files

…asswords.

…rent handling.

birschick-bq · 2024-12-05T19:50:43Z

csharp/src/Apache.Arrow.Adbc/Tracing/TracingBase.cs

+        /// <summary>
+        /// Gets the name of the <see cref="System.Diagnostics.ActivitySource"/>
+        /// </summary>
+        public string ActivitySourceName => ActivitySource.Name;


This is an update to the public API. Is this allowed? Or will we need to stage this at a later time?

An alternative is to take a Driver/Connection property that sets the name of the ActivitySource.

birschick-bq added 3 commits October 31, 2024 13:40

optel poc - wip #1

27c808c

Initial POC for using System.Diagnostics

2384ed4

Merge branch 'main' into dev/birschick-bq/open-telemetry-poc

3824499

birschick-bq changed the title ~~Logging/Tracing POC~~ feat(csharp/src/csharp/Drivers/Apache): tracing proof-of-concept Nov 8, 2024

remove go code

351ced6

birschick-bq changed the title ~~feat(csharp/src/csharp/Drivers/Apache): tracing proof-of-concept~~ feat(csharp/src/Drivers/Apache): tracing proof-of-concept Nov 8, 2024

birschick-bq added 11 commits November 8, 2024 10:19

moved tracing to Connection. Removed from Database/Driver

49f9a72

moved tracing to Connection. Removed from Database/Driver

4af814a

add comments about listener lifetimes

9bf476c

remove go code

2be0142

remove updates to tests

4b7997e

update exception handling

1b87b4f

remove go

1264d78

more instrumentation and exception handling

753038e

improved modularization

5749d7a

remove unnecessary updates

b30524f

Merge branch 'main' into dev/birschick-bq/open-telemetry-poc

cfbebb3

birschick-bq added 4 commits November 14, 2024 11:17

updates from review comments to move the tracing code to make easier …

b77490b

…to inherit

some clean-up and documentation

c4837c4

fix trailing space

ea7b873

small update and tracing instrumentation for SparkDatabricksReader

a379b23

birschick-bq commented Nov 14, 2024

View reviewed changes

csharp/src/Drivers/Apache/Apache.Arrow.Adbc.Drivers.Apache.csproj Outdated Show resolved Hide resolved

refactored TracingConnection to use common implementation. Added supp…

c018d39

…ort for AdbcConnection11 and AdbcStatement11

birschick-bq commented Nov 14, 2024

View reviewed changes

csharp/src/Apache.Arrow.Adbc/Tracing/TracingConnectionImpl.cs Outdated Show resolved Hide resolved

birschick-bq commented Nov 14, 2024

View reviewed changes

csharp/src/Drivers/Apache/Hive2/HiveServer2Connection.cs Outdated Show resolved Hide resolved

birschick-bq added 4 commits November 14, 2024 14:06

refactored TraceException

d935264

corrected implementation

4d874bc

refactor tracing base

40a067d

remove unnecessary changes

acc0a1b

birschick-bq added 16 commits November 22, 2024 10:09

correct tests - invalid file characters

65cbc95

correct tests - max trace files

d072479

correct tests - single trace file

1d68327

refactor where tracing options are handled. handle options for file s…

a3b9584

…ize and number of files

remove tracing of all properties/options - might include tokens and p…

40dad00

…asswords.

validate trace folder is writable

a3d84c9

ensure folder before folder validation

be09ea8

update Spark driver documentation for file tracing options

94ae794

Merge branch 'main' into dev/birschick-bq/open-telemetry-poc

fa2dca6

Merge branch 'main' into dev/birschick-bq/open-telemetry-poc

04e19c1

initial commit for setting the traceParent

9c6a420

small fixes for setting the traceParent

69d4345

small doc updates

afd7ea6

refactored how boiler place code is handled

8bd877a

some renameing and coumentation

7b58323

fixed formatting

015bc90

birschick-bq changed the title ~~feat(csharp/src/Drivers/Apache): tracing proof-of-concept~~ feat(csharp/src/Drivers/Apache): tracing - work-in-progress Dec 2, 2024

Repository owner deleted a comment from davidhcoe Dec 2, 2024

birschick-bq added 7 commits December 3, 2024 09:57

add improved test for traceParent.

cb79fa7

Merge branch 'main' into dev/birschick-bq/open-telemetry-poc

4ac1789

update tests

cb3b6f2

Improvement for output format and ingestion. Improvements for tracePa…

50e16e4

…rent handling.

Add extension methods to ease of creating Events and Links

1cd083f

Documentation update

9f182b4

Add public property for ActivitySourceName

12882ab

birschick-bq commented Dec 5, 2024

View reviewed changes

birschick-bq added 2 commits December 10, 2024 11:01

Merge branch 'main' into dev/birschick-bq/open-telemetry-poc

600735d

Merge branch 'main' into dev/birschick-bq/open-telemetry-poc

fe60b80

birschick-bq added a commit that referenced this pull request Dec 12, 2024

remove more instrumentation code #5

c3cfa50

Merge branch 'main' into dev/birschick-bq/open-telemetry-poc

1ccc858

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

feat(csharp/src/Drivers/Apache): tracing - work-in-progress #5

feat(csharp/src/Drivers/Apache): tracing - work-in-progress #5

birschick-bq commented Nov 7, 2024 •

edited

Loading

davidhcoe commented Nov 11, 2024

birschick-bq Dec 5, 2024

birschick-bq Dec 5, 2024

feat(csharp/src/Drivers/Apache): tracing - work-in-progress #5

Are you sure you want to change the base?

feat(csharp/src/Drivers/Apache): tracing - work-in-progress #5

Conversation

birschick-bq commented Nov 7, 2024 • edited Loading

POC

Assumptions

CSharp

Sample output:

Successful activity (multiple calls to ExecuteUpdateAsync)

Exception activity

Instrumentation

Exporting

Missing Features

davidhcoe commented Nov 11, 2024

birschick-bq Dec 5, 2024

Choose a reason for hiding this comment

birschick-bq Dec 5, 2024

Choose a reason for hiding this comment

birschick-bq commented Nov 7, 2024 •

edited

Loading

Successful activity (multiple calls to `ExecuteUpdateAsync`)