Grcov report - grpc_access_log

1

#include "source/extensions/access_loggers/grpc/grpc_access_log_utils.h"

2

3

#include "envoy/data/accesslog/v3/accesslog.pb.h"

4

#include "envoy/extensions/access_loggers/grpc/v3/als.pb.h"

5

#include "envoy/stream_info/filter_state.h"

6

#include "envoy/upstream/upstream.h"

7

8

#include "source/common/network/utility.h"

9

#include "source/common/stream_info/utility.h"

10

#include "source/common/tracing/custom_tag_impl.h"

11

#include "source/common/tracing/http_tracer_impl.h"

12

13

namespace Envoy {

14

namespace Extensions {

15

namespace AccessLoggers {

16

namespace GrpcCommon {

17

18

namespace {

19

20

using namespace envoy::data::accesslog::v3;

21

22

// Helper function to convert from a BoringSSL textual representation of the

23

// TLS version to the corresponding enum value used in gRPC access logs.

24

15

TLSProperties_TLSVersion tlsVersionStringToEnum(const std::string& tls_version) {

25

15

  if (tls_version == "TLSv1") {

26

1

    return TLSProperties::TLSv1;

27

14

  } else if (tls_version == "TLSv1.1") {

28

1

    return TLSProperties::TLSv1_1;

29

13

  } else if (tls_version == "TLSv1.2") {

30

11

    return TLSProperties::TLSv1_2;

31

12

  } else if (tls_version == "TLSv1.3") {

32

1

    return TLSProperties::TLSv1_3;

33

1

34

35

1

  return TLSProperties::VERSION_UNSPECIFIED;

36

15

37

38

} // namespace

39

40

CommonPropertiesConfig::CommonPropertiesConfig(

41

    const ProtoCommonGrpcAccessLogConfig& config,

42

    const Formatter::CommandParserPtrVector& command_parsers)

43

52

    : filter_states_to_log(config.filter_state_objects_to_log().begin(),

44

52

                           config.filter_state_objects_to_log().end()) {

45

52

  for (const auto& custom_tag : config.custom_tags()) {

46

8

    const auto tag_applier =

47

8

        Tracing::CustomTagUtility::createCustomTag(custom_tag, command_parsers);

48

8

    custom_tags.push_back(tag_applier);

49

8

50

52

51

52

void Utility::responseFlagsToAccessLogResponseFlags(

53

    envoy::data::accesslog::v3::AccessLogCommon& common_access_log,

54

72

    const StreamInfo::StreamInfo& stream_info) {

55

56

72

  static_assert(StreamInfo::CoreResponseFlag::LastFlag == 29,

57

72

                "A flag has been added. Fix this code.");

58

59

72

  if (stream_info.hasResponseFlag(StreamInfo::CoreResponseFlag::FailedLocalHealthCheck)) {

60

4

    common_access_log.mutable_response_flags()->set_failed_local_healthcheck(true);

61

4

62

63

72

  if (stream_info.hasResponseFlag(StreamInfo::CoreResponseFlag::NoHealthyUpstream)) {

64

4

    common_access_log.mutable_response_flags()->set_no_healthy_upstream(true);

65

4

66

67

72

  if (stream_info.hasResponseFlag(StreamInfo::CoreResponseFlag::UpstreamRequestTimeout)) {

68

4

    common_access_log.mutable_response_flags()->set_upstream_request_timeout(true);

69

4

70

71

72

  if (stream_info.hasResponseFlag(StreamInfo::CoreResponseFlag::LocalReset)) {

72

4

    common_access_log.mutable_response_flags()->set_local_reset(true);

73

4

74

75

72

  if (stream_info.hasResponseFlag(StreamInfo::CoreResponseFlag::UpstreamRemoteReset)) {

76

4

    common_access_log.mutable_response_flags()->set_upstream_remote_reset(true);

77

4

78

79

72

  if (stream_info.hasResponseFlag(StreamInfo::CoreResponseFlag::UpstreamConnectionFailure)) {

80

4

    common_access_log.mutable_response_flags()->set_upstream_connection_failure(true);

81

4

82

83

72

  if (stream_info.hasResponseFlag(StreamInfo::CoreResponseFlag::UpstreamConnectionTermination)) {

84

4

    common_access_log.mutable_response_flags()->set_upstream_connection_termination(true);

85

4

86

87

72

  if (stream_info.hasResponseFlag(StreamInfo::CoreResponseFlag::UpstreamOverflow)) {

88

4

    common_access_log.mutable_response_flags()->set_upstream_overflow(true);

89

4

90

91

72

  if (stream_info.hasResponseFlag(StreamInfo::CoreResponseFlag::NoRouteFound)) {

92

10

    common_access_log.mutable_response_flags()->set_no_route_found(true);

93

10

94

95

72

  if (stream_info.hasResponseFlag(StreamInfo::CoreResponseFlag::DelayInjected)) {

96

4

    common_access_log.mutable_response_flags()->set_delay_injected(true);

97

4

98

99

72

  if (stream_info.hasResponseFlag(StreamInfo::CoreResponseFlag::FaultInjected)) {

100

5

    common_access_log.mutable_response_flags()->set_fault_injected(true);

101

5

102

103

72

  if (stream_info.hasResponseFlag(StreamInfo::CoreResponseFlag::RateLimited)) {

104

4

    common_access_log.mutable_response_flags()->set_rate_limited(true);

105

4

106

107

72

  if (stream_info.hasResponseFlag(StreamInfo::CoreResponseFlag::UnauthorizedExternalService)) {

108

4

    common_access_log.mutable_response_flags()->mutable_unauthorized_details()->set_reason(

109

4

        envoy::data::accesslog::v3::ResponseFlags::Unauthorized::EXTERNAL_SERVICE);

110

4

111

112

72

  if (stream_info.hasResponseFlag(StreamInfo::CoreResponseFlag::RateLimitServiceError)) {

113

4

    common_access_log.mutable_response_flags()->set_rate_limit_service_error(true);

114

4

115

116

72

  if (stream_info.hasResponseFlag(StreamInfo::CoreResponseFlag::DownstreamConnectionTermination)) {

117

4

    common_access_log.mutable_response_flags()->set_downstream_connection_termination(true);

118

4

119

120

72

  if (stream_info.hasResponseFlag(StreamInfo::CoreResponseFlag::UpstreamRetryLimitExceeded)) {

121

4

    common_access_log.mutable_response_flags()->set_upstream_retry_limit_exceeded(true);

122

4

123

124

72

  if (stream_info.hasResponseFlag(StreamInfo::CoreResponseFlag::StreamIdleTimeout)) {

125

4

    common_access_log.mutable_response_flags()->set_stream_idle_timeout(true);

126

4

127

128

72

  if (stream_info.hasResponseFlag(StreamInfo::CoreResponseFlag::InvalidEnvoyRequestHeaders)) {

129

4

    common_access_log.mutable_response_flags()->set_invalid_envoy_request_headers(true);

130

4

131

132

72

  if (stream_info.hasResponseFlag(StreamInfo::CoreResponseFlag::DownstreamProtocolError)) {

133

4

    common_access_log.mutable_response_flags()->set_downstream_protocol_error(true);

134

4

135

136

72

  if (stream_info.hasResponseFlag(StreamInfo::CoreResponseFlag::UpstreamMaxStreamDurationReached)) {

137

4

    common_access_log.mutable_response_flags()->set_upstream_max_stream_duration_reached(true);

138

4

139

140

72

  if (stream_info.hasResponseFlag(StreamInfo::CoreResponseFlag::ResponseFromCacheFilter)) {

141

4

    common_access_log.mutable_response_flags()->set_response_from_cache_filter(true);

142

4

143

144

72

  if (stream_info.hasResponseFlag(StreamInfo::CoreResponseFlag::NoFilterConfigFound)) {

145

4

    common_access_log.mutable_response_flags()->set_no_filter_config_found(true);

146

4

147

148

72

  if (stream_info.hasResponseFlag(StreamInfo::CoreResponseFlag::DurationTimeout)) {

149

4

    common_access_log.mutable_response_flags()->set_duration_timeout(true);

150

4

151

152

72

  if (stream_info.hasResponseFlag(StreamInfo::CoreResponseFlag::UpstreamProtocolError)) {

153

4

    common_access_log.mutable_response_flags()->set_upstream_protocol_error(true);

154

4

155

156

72

  if (stream_info.hasResponseFlag(StreamInfo::CoreResponseFlag::NoClusterFound)) {

157

4

    common_access_log.mutable_response_flags()->set_no_cluster_found(true);

158

4

159

160

72

  if (stream_info.hasResponseFlag(StreamInfo::CoreResponseFlag::OverloadManager)) {

161

4

    common_access_log.mutable_response_flags()->set_overload_manager(true);

162

4

163

164

72

  if (stream_info.hasResponseFlag(StreamInfo::CoreResponseFlag::DnsResolutionFailed)) {

165

4

    common_access_log.mutable_response_flags()->set_dns_resolution_failure(true);

166

4

167

168

72

  if (stream_info.hasResponseFlag(StreamInfo::CoreResponseFlag::DownstreamRemoteReset)) {

169

4

    common_access_log.mutable_response_flags()->set_downstream_remote_reset(true);

170

4

171

72

172

173

void Utility::extractCommonAccessLogProperties(

174

    envoy::data::accesslog::v3::AccessLogCommon& common_access_log,

175

    const CommonPropertiesConfig& config, const Http::RequestHeaderMap& request_header,

176

71

    const StreamInfo::StreamInfo& stream_info, const Formatter::Context& formatter_context) {

177

  // TODO(mattklein123): Populate sample_rate field.

178

71

  if (stream_info.downstreamAddressProvider().remoteAddress() != nullptr) {

179

71

    Network::Utility::addressToProtobufAddress(

180

71

        *stream_info.downstreamAddressProvider().remoteAddress(),

181

71

        *common_access_log.mutable_downstream_remote_address());

182

71

183

71

  if (stream_info.downstreamAddressProvider().directRemoteAddress() != nullptr) {

184

71

    Network::Utility::addressToProtobufAddress(

185

71

        *stream_info.downstreamAddressProvider().directRemoteAddress(),

186

71

        *common_access_log.mutable_downstream_direct_remote_address());

187

71

188

71

  if (stream_info.downstreamAddressProvider().localAddress() != nullptr) {

189

71

    Network::Utility::addressToProtobufAddress(

190

71

        *stream_info.downstreamAddressProvider().localAddress(),

191

71

        *common_access_log.mutable_downstream_local_address());

192

71

193

71

  if (!stream_info.downstreamAddressProvider().requestedServerName().empty()) {

194

13

    common_access_log.mutable_tls_properties()->set_tls_sni_hostname(

195

13

        MessageUtil::sanitizeUtf8String(

196

13

            stream_info.downstreamAddressProvider().requestedServerName()));

197

13

198

71

  if (!stream_info.downstreamAddressProvider().ja3Hash().empty()) {

199

6

    common_access_log.mutable_tls_properties()->set_ja3_fingerprint(

200

6

        std::string(stream_info.downstreamAddressProvider().ja3Hash()));

201

6

202

71

  if (stream_info.downstreamAddressProvider().sslConnection() != nullptr) {

203

15

    auto* tls_properties = common_access_log.mutable_tls_properties();

204

15

    const Ssl::ConnectionInfoConstSharedPtr downstream_ssl_connection =

205

15

        stream_info.downstreamAddressProvider().sslConnection();

206

207

15

    auto* local_properties = tls_properties->mutable_local_certificate_properties();

208

25

    for (const auto& uri_san : downstream_ssl_connection->uriSanLocalCertificate()) {

209

22

      auto* local_san = local_properties->add_subject_alt_name();

210

22

      local_san->set_uri(MessageUtil::sanitizeUtf8String(uri_san));

211

22

212

15

    local_properties->set_subject(

213

15

        MessageUtil::sanitizeUtf8String(downstream_ssl_connection->subjectLocalCertificate()));

214

215

15

    auto* peer_properties = tls_properties->mutable_peer_certificate_properties();

216

17

    for (const auto& uri_san : downstream_ssl_connection->uriSanPeerCertificate()) {

217

14

      auto* peer_san = peer_properties->add_subject_alt_name();

218

14

      peer_san->set_uri(MessageUtil::sanitizeUtf8String(uri_san));

219

14

220

221

15

    peer_properties->set_subject(downstream_ssl_connection->subjectPeerCertificate());

222

15

    peer_properties->set_issuer(

223

15

        MessageUtil::sanitizeUtf8String(downstream_ssl_connection->issuerPeerCertificate()));

224

225

15

    tls_properties->set_tls_session_id(

226

15

        MessageUtil::sanitizeUtf8String(downstream_ssl_connection->sessionId()));

227

15

    tls_properties->set_tls_version(

228

15

        tlsVersionStringToEnum(downstream_ssl_connection->tlsVersion()));

229

230

15

    auto* local_tls_cipher_suite = tls_properties->mutable_tls_cipher_suite();

231

15

    local_tls_cipher_suite->set_value(downstream_ssl_connection->ciphersuiteId());

232

15

233

71

  common_access_log.mutable_start_time()->MergeFrom(

234

71

      Protobuf::util::TimeUtil::NanosecondsToTimestamp(

235

71

          std::chrono::duration_cast<std::chrono::nanoseconds>(

236

71

              stream_info.startTime().time_since_epoch())

237

71

              .count()));

238

239

71

  absl::optional<std::chrono::nanoseconds> dur = stream_info.requestComplete();

240

71

  if (dur) {

241

64

    common_access_log.mutable_duration()->MergeFrom(

242

64

        Protobuf::util::TimeUtil::NanosecondsToDuration(dur.value().count()));

243

64

244

245

71

  StreamInfo::TimingUtility timing(stream_info);

246

71

  dur = timing.lastDownstreamRxByteReceived();

247

71

  if (dur) {

248

17

    common_access_log.mutable_time_to_last_rx_byte()->MergeFrom(

249

17

        Protobuf::util::TimeUtil::NanosecondsToDuration(dur.value().count()));

250

17

251

252

71

  dur = timing.firstUpstreamTxByteSent();

253

71

  if (dur) {

254

13

    common_access_log.mutable_time_to_first_upstream_tx_byte()->MergeFrom(

255

13

        Protobuf::util::TimeUtil::NanosecondsToDuration(dur.value().count()));

256

13

257

258

71

  dur = timing.lastUpstreamTxByteSent();

259

71

  if (dur) {

260

13

    common_access_log.mutable_time_to_last_upstream_tx_byte()->MergeFrom(

261

13

        Protobuf::util::TimeUtil::NanosecondsToDuration(dur.value().count()));

262

13

263

264

71

  dur = timing.firstUpstreamRxByteReceived();

265

71

  if (dur) {

266

13

    common_access_log.mutable_time_to_first_upstream_rx_byte()->MergeFrom(

267

13

        Protobuf::util::TimeUtil::NanosecondsToDuration(dur.value().count()));

268

13

269

270

71

  dur = timing.lastUpstreamRxByteReceived();

271

71

  if (dur) {

272

13

    common_access_log.mutable_time_to_last_upstream_rx_byte()->MergeFrom(

273

13

        Protobuf::util::TimeUtil::NanosecondsToDuration(dur.value().count()));

274

13

275

276

71

  dur = timing.firstDownstreamTxByteSent();

277

71

  if (dur) {

278

17

    common_access_log.mutable_time_to_first_downstream_tx_byte()->MergeFrom(

279

17

        Protobuf::util::TimeUtil::NanosecondsToDuration(dur.value().count()));

280

17

281

282

71

  dur = timing.lastDownstreamTxByteSent();

283

71

  if (dur) {

284

20

    common_access_log.mutable_time_to_last_downstream_tx_byte()->MergeFrom(

285

20

        Protobuf::util::TimeUtil::NanosecondsToDuration(dur.value().count()));

286

20

287

288

71

  if (stream_info.upstreamInfo().has_value()) {

289

49

    const auto& upstream_info = stream_info.upstreamInfo().value().get();

290

49

    if (upstream_info.upstreamHost() != nullptr) {

291

29

      Network::Utility::addressToProtobufAddress(

292

29

          *upstream_info.upstreamHost()->address(),

293

29

          *common_access_log.mutable_upstream_remote_address());

294

29

      common_access_log.set_upstream_cluster(upstream_info.upstreamHost()->cluster().name());

295

29

296

49

    if (upstream_info.upstreamLocalAddress() != nullptr) {

297

49

      Network::Utility::addressToProtobufAddress(

298

49

          *upstream_info.upstreamLocalAddress(),

299

49

          *common_access_log.mutable_upstream_local_address());

300

49

301

49

    if (!upstream_info.upstreamTransportFailureReason().empty()) {

302

1

      common_access_log.set_upstream_transport_failure_reason(

303

1

          upstream_info.upstreamTransportFailureReason());

304

1

305

49

306

71

  if (!stream_info.getRouteName().empty()) {

307

1

    common_access_log.set_route_name(stream_info.getRouteName());

308

1

309

71

  if (stream_info.attemptCount().has_value()) {

310

19

    common_access_log.set_upstream_request_attempt_count(stream_info.attemptCount().value());

311

19

312

71

  if (stream_info.connectionTerminationDetails().has_value()) {

313

2

    common_access_log.set_connection_termination_details(

314

2

        stream_info.connectionTerminationDetails().value());

315

2

316

317

71

  responseFlagsToAccessLogResponseFlags(common_access_log, stream_info);

318

71

  if (stream_info.dynamicMetadata().filter_metadata_size() > 0) {

319

2

    common_access_log.mutable_metadata()->MergeFrom(stream_info.dynamicMetadata());

320

2

321

322

121

  for (const auto& key : config.filter_states_to_log) {

323

78

    if (!(extractFilterStateData(stream_info.filterState(), key, common_access_log))) {

324

70

      if (stream_info.upstreamInfo().has_value() &&

325

70

          stream_info.upstreamInfo()->upstreamFilterState() != nullptr) {

326

1

        extractFilterStateData(*(stream_info.upstreamInfo()->upstreamFilterState()), key,

327

1

                               common_access_log);

328

1

329

70

330

78

331

332

71

  Tracing::ReadOnlyHttpTraceContext trace_context(request_header);

333

71

  Tracing::CustomTagContext ctx{trace_context, stream_info, formatter_context};

334

71

  for (const auto& custom_tag : config.custom_tags) {

335

7

    custom_tag->applyLog(common_access_log, ctx);

336

7

337

338

  // If the stream is not complete, then this log entry is intermediate log entry.

339

71

  if (!stream_info.requestComplete().has_value()) {

340

7

    common_access_log.set_intermediate_log_entry(true); // Deprecated field

341

7

342

343

  // Set stream unique id from the stream info.

344

71

  if (auto provider = stream_info.getStreamIdProvider(); provider.has_value()) {

345

25

    common_access_log.set_stream_id(std::string(provider->toStringView().value_or("")));

346

25

347

348

71

  if (const auto& reason = stream_info.downstreamTransportFailureReason(); !reason.empty()) {

349

6

    common_access_log.set_downstream_transport_failure_reason(reason);

350

6

351

352

71

  if (const auto& bytes_meter = stream_info.getDownstreamBytesMeter(); bytes_meter != nullptr) {

353

27

    common_access_log.set_downstream_wire_bytes_sent(bytes_meter->wireBytesSent());

354

27

    common_access_log.set_downstream_wire_bytes_received(bytes_meter->wireBytesReceived());

355

27

356

71

  if (const auto& bytes_meter = stream_info.getUpstreamBytesMeter(); bytes_meter != nullptr) {

357

43

    common_access_log.set_upstream_wire_bytes_sent(bytes_meter->wireBytesSent());

358

43

    common_access_log.set_upstream_wire_bytes_received(bytes_meter->wireBytesReceived());

359

43

360

361

71

  common_access_log.set_access_log_type(formatter_context.accessLogType());

362

71

363

364

bool extractFilterStateData(const StreamInfo::FilterState& filter_state, const std::string& key,

365

79

                            envoy::data::accesslog::v3::AccessLogCommon& common_access_log) {

366

79

  if (auto state = filter_state.getDataReadOnlyGeneric(key); state != nullptr) {

367

9

    ProtobufTypes::MessagePtr serialized_proto = state->serializeAsProto();

368

9

    if (serialized_proto != nullptr) {

369

9

      auto& filter_state_objects = *common_access_log.mutable_filter_state_objects();

370

9

      Protobuf::Any& any = filter_state_objects[key];

371

9

      if (dynamic_cast<Protobuf::Any*>(serialized_proto.get()) != nullptr) {

372

5

        any.Swap(dynamic_cast<Protobuf::Any*>(serialized_proto.get()));

373

7

      } else {

374

4

        any.PackFrom(*serialized_proto);

375

4

376

9

377

9

    return true;

378

9

379

70

  return false;

380

79

381

382

} // namespace GrpcCommon

383

} // namespace AccessLoggers

384

} // namespace Extensions

385

} // namespace Envoy