Skip to content

Commit 330efe6

Browse files
k8s-ci-robotk8s-ci-robot
authored
Merge pull request #409 from davidz627/feature/logSuccess
Clean up all logging for the driver, log successes in all cases
2 parents b533c40 + eb56ce8 commit 330efe6

File tree

8 files changed

+61
-76
lines changed

8 files changed

+61
-76
lines changed

‎cmd/main.go

+6-1
Original file line numberDiff line numberDiff line change
@@ -43,6 +43,11 @@ const (
4343
)
4444

4545
func init() {
46+
// klog verbosity guide for this package
47+
// Use V(2) for one time config information
48+
// Use V(4) for general debug information logging
49+
// Use V(5) for GCE Cloud Provider Call informational logging
50+
// Use V(6) for extra repeated/polling information
4651
klog.InitFlags(flag.CommandLine)
4752
}
4853

@@ -57,7 +62,7 @@ func handle() {
5762
if vendorVersion == "" {
5863
klog.Fatalf("vendorVersion must be set at compile time")
5964
}
60-
klog.V(4).Infof("Driver vendor version %v", vendorVersion)
65+
klog.V(2).Infof("Driver vendor version %v", vendorVersion)
6166

6267
gceDriver := driver.GetGCEDriver()
6368

‎pkg/gce-cloud-provider/compute/gce-compute.go

+22-17
Original file line numberDiff line numberDiff line change
@@ -65,6 +65,7 @@ type GCECompute interface {
6565
// RepairUnderspecifiedVolumeKey will query the cloud provider and check each zone for the disk specified
6666
// by the volume key and return a volume key with a correct zone
6767
func (cloud *CloudProvider) RepairUnderspecifiedVolumeKey(ctx context.Context, volumeKey *meta.Key) (*meta.Key, error) {
68+
klog.V(5).Infof("Repairing potentially underspecified volume key %v", volumeKey)
6869
region, err := common.GetRegionFromZones([]string{cloud.zone})
6970
if err != nil {
7071
return nil, fmt.Errorf("failed to get region from zones: %v", err)
@@ -114,6 +115,7 @@ func (cloud *CloudProvider) RepairUnderspecifiedVolumeKey(ctx context.Context, v
114115
}
115116

116117
func (cloud *CloudProvider) ListZones(ctx context.Context, region string) ([]string, error) {
118+
klog.V(5).Infof("Listing zones in region: %v", region)
117119
if len(cloud.zonesCache[region]) > 0 {
118120
return cloud.zonesCache[region], nil
119121
}
@@ -131,6 +133,7 @@ func (cloud *CloudProvider) ListZones(ctx context.Context, region string) ([]str
131133
}
132134

133135
func (cloud *CloudProvider) ListSnapshots(ctx context.Context, filter string, maxEntries int64, pageToken string) ([]*computev1.Snapshot, string, error) {
136+
klog.V(5).Infof("Listing snapshots with filter: %s, max entries: %v, page token: %s", filter, maxEntries, pageToken)
134137
snapshots := []*computev1.Snapshot{}
135138
snapshotList, err := cloud.service.Snapshots.List(cloud.project).Filter(filter).MaxResults(maxEntries).PageToken(pageToken).Do()
136139
if err != nil {
@@ -144,6 +147,7 @@ func (cloud *CloudProvider) ListSnapshots(ctx context.Context, filter string, ma
144147
}
145148

146149
func (cloud *CloudProvider) GetDisk(ctx context.Context, key *meta.Key) (*CloudDisk, error) {
150+
klog.V(5).Infof("Getting disk %v", key)
147151
switch key.Type() {
148152
case meta.Zonal:
149153
disk, err := cloud.getZonalDiskOrError(ctx, key.Zone, key.Name)
@@ -159,23 +163,20 @@ func (cloud *CloudProvider) GetDisk(ctx context.Context, key *meta.Key) (*CloudD
159163
func (cloud *CloudProvider) getZonalDiskOrError(ctx context.Context, volumeZone, volumeName string) (*computev1.Disk, error) {
160164
svc := cloud.service
161165
project := cloud.project
162-
klog.V(4).Infof("Getting disk %v from zone %v", volumeName, volumeZone)
166+
163167
disk, err := svc.Disks.Get(project, volumeZone, volumeName).Context(ctx).Do()
164168
if err != nil {
165169
return nil, err
166170
}
167-
klog.V(4).Infof("Got disk %v from zone %v", volumeName, volumeZone)
168171
return disk, nil
169172
}
170173

171174
func (cloud *CloudProvider) getRegionalDiskOrError(ctx context.Context, volumeRegion, volumeName string) (*computev1.Disk, error) {
172175
project := cloud.project
173-
klog.V(4).Infof("Getting disk %v from region %v", volumeName, volumeRegion)
174176
disk, err := cloud.service.RegionDisks.Get(project, volumeRegion, volumeName).Context(ctx).Do()
175177
if err != nil {
176178
return nil, err
177179
}
178-
klog.V(4).Infof("Got disk %v from region %v", volumeName, volumeRegion)
179180
return disk, nil
180181
}
181182

@@ -194,6 +195,7 @@ func (cloud *CloudProvider) getRegionURI(region string) string {
194195
}
195196

196197
func (cloud *CloudProvider) ValidateExistingDisk(ctx context.Context, resp *CloudDisk, diskType string, reqBytes, limBytes int64) error {
198+
klog.V(5).Infof("Validating existing disk %v with diskType: %s, reqested bytes: %v, limit bytes: %v", resp, diskType, reqBytes, limBytes)
197199
if resp == nil {
198200
return fmt.Errorf("disk does not exist")
199201
}
@@ -212,13 +214,11 @@ func (cloud *CloudProvider) ValidateExistingDisk(ctx context.Context, resp *Clou
212214
return fmt.Errorf("disk already exists with incompatible type. Need %v. Got %v",
213215
diskType, respType[len(respType)-1])
214216
}
215-
216-
// Volume exists with matching name, capacity, type.
217-
klog.V(4).Infof("Compatible disk already exists. Reusing existing.")
218217
return nil
219218
}
220219

221220
func (cloud *CloudProvider) InsertDisk(ctx context.Context, volKey *meta.Key, diskType string, capBytes int64, capacityRange *csi.CapacityRange, replicaZones []string, snapshotID, diskEncryptionKmsKey string) error {
221+
klog.V(5).Infof("Inserting disk %v", volKey)
222222
switch volKey.Type() {
223223
case meta.Zonal:
224224
return cloud.insertZonalDisk(ctx, volKey, diskType, capBytes, capacityRange, snapshotID, diskEncryptionKmsKey)
@@ -349,6 +349,7 @@ func (cloud *CloudProvider) insertZonalDisk(ctx context.Context, volKey *meta.Ke
349349
}
350350

351351
func (cloud *CloudProvider) DeleteDisk(ctx context.Context, volKey *meta.Key) error {
352+
klog.V(5).Infof("Deleting disk: %v", volKey)
352353
switch volKey.Type() {
353354
case meta.Zonal:
354355
return cloud.deleteZonalDisk(ctx, volKey.Zone, volKey.Name)
@@ -392,6 +393,7 @@ func (cloud *CloudProvider) deleteRegionalDisk(ctx context.Context, region, name
392393
}
393394

394395
func (cloud *CloudProvider) AttachDisk(ctx context.Context, volKey *meta.Key, readWrite, diskType, instanceZone, instanceName string) error {
396+
klog.V(5).Infof("Attaching disk %v to %s", volKey, instanceName)
395397
source := cloud.GetDiskSourceURI(volKey)
396398

397399
deviceName, err := common.GetDeviceName(volKey)
@@ -418,6 +420,7 @@ func (cloud *CloudProvider) AttachDisk(ctx context.Context, volKey *meta.Key, re
418420
}
419421

420422
func (cloud *CloudProvider) DetachDisk(ctx context.Context, deviceName, instanceZone, instanceName string) error {
423+
klog.V(5).Infof("Detaching disk %v from %v", deviceName, instanceName)
421424
op, err := cloud.service.Instances.DetachDisk(cloud.project, instanceZone, instanceName, deviceName).Context(ctx).Do()
422425
if err != nil {
423426
return err
@@ -516,11 +519,13 @@ func (cloud *CloudProvider) waitForGlobalOp(ctx context.Context, op *computev1.O
516519
}
517520

518521
func (cloud *CloudProvider) WaitForAttach(ctx context.Context, volKey *meta.Key, instanceZone, instanceName string) error {
522+
klog.V(5).Infof("Waiting for attach of disk %v to instance %v to complete...", volKey.Name, instanceName)
523+
start := time.Now()
519524
return wait.Poll(5*time.Second, 2*time.Minute, func() (bool, error) {
525+
klog.V(6).Infof("Polling for attach of disk %v to instance %v to complete for %v", volKey.Name, instanceName, time.Since(start))
520526
disk, err := cloud.GetDisk(ctx, volKey)
521527
if err != nil {
522-
klog.Errorf("GetDisk failed to get disk: %v", err)
523-
return false, err
528+
return false, fmt.Errorf("GetDisk failed to get disk: %v", err)
524529
}
525530

526531
if disk == nil {
@@ -547,31 +552,29 @@ func opIsDone(op *computev1.Operation) (bool, error) {
547552
}
548553

549554
func (cloud *CloudProvider) GetInstanceOrError(ctx context.Context, instanceZone, instanceName string) (*computev1.Instance, error) {
555+
klog.V(5).Infof("Getting instance %v from zone %v", instanceName, instanceZone)
550556
svc := cloud.service
551557
project := cloud.project
552-
klog.V(4).Infof("Getting instance %v from zone %v", instanceName, instanceZone)
553-
554558
instance, err := svc.Instances.Get(project, instanceZone, instanceName).Do()
555559
if err != nil {
556560
return nil, err
557561
}
558-
klog.V(4).Infof("Got instance %v from zone %v", instanceName, instanceZone)
559562
return instance, nil
560563
}
561564

562565
func (cloud *CloudProvider) GetSnapshot(ctx context.Context, snapshotName string) (*computev1.Snapshot, error) {
566+
klog.V(5).Infof("Getting snapshot %v", snapshotName)
563567
svc := cloud.service
564568
project := cloud.project
565-
klog.V(4).Infof("Getting snapshot %v", snapshotName)
566569
snapshot, err := svc.Snapshots.Get(project, snapshotName).Context(ctx).Do()
567570
if err != nil {
568571
return nil, err
569572
}
570-
klog.V(4).Infof("Got snapshot %v", snapshotName)
571573
return snapshot, nil
572574
}
573575

574576
func (cloud *CloudProvider) DeleteSnapshot(ctx context.Context, snapshotName string) error {
577+
klog.V(5).Infof("Deleting snapshot %v", snapshotName)
575578
op, err := cloud.service.Snapshots.Delete(cloud.project, snapshotName).Context(ctx).Do()
576579
if err != nil {
577580
if IsGCEError(err, "notFound") {
@@ -588,6 +591,7 @@ func (cloud *CloudProvider) DeleteSnapshot(ctx context.Context, snapshotName str
588591
}
589592

590593
func (cloud *CloudProvider) CreateSnapshot(ctx context.Context, volKey *meta.Key, snapshotName string) (*computev1.Snapshot, error) {
594+
klog.V(5).Infof("Creating snapshot %s for volume %v", snapshotName, volKey)
591595
switch volKey.Type() {
592596
case meta.Zonal:
593597
return cloud.createZonalDiskSnapshot(ctx, volKey, snapshotName)
@@ -599,6 +603,7 @@ func (cloud *CloudProvider) CreateSnapshot(ctx context.Context, volKey *meta.Key
599603
}
600604

601605
func (cloud *CloudProvider) ResizeDisk(ctx context.Context, volKey *meta.Key, requestBytes int64) (int64, error) {
606+
klog.V(5).Infof("Resizing disk %v to size %v", volKey, requestBytes)
602607
cloudDisk, err := cloud.GetDisk(ctx, volKey)
603608
if err != nil {
604609
return -1, fmt.Errorf("failed to get disk: %v", err)
@@ -694,16 +699,16 @@ func (cloud *CloudProvider) waitForSnapshotCreation(ctx context.Context, snapsho
694699
for {
695700
select {
696701
case <-ticker.C:
697-
klog.V(5).Infof("Checking GCE Snapshot %s.", snapshotName)
702+
klog.V(6).Infof("Checking GCE Snapshot %s.", snapshotName)
698703
snapshot, err := cloud.GetSnapshot(ctx, snapshotName)
699704
if err != nil {
700705
klog.Warningf("Error in getting snapshot %s, %v", snapshotName, err)
701706
} else if snapshot != nil {
702707
if snapshot.Status != "CREATING" {
703-
klog.V(5).Infof("Snapshot %s status is %s", snapshotName, snapshot.Status)
708+
klog.V(6).Infof("Snapshot %s status is %s", snapshotName, snapshot.Status)
704709
return snapshot, nil
705710
} else {
706-
klog.V(5).Infof("Snapshot %s is still creating ...", snapshotName)
711+
klog.V(6).Infof("Snapshot %s is still creating ...", snapshotName)
707712
}
708713
}
709714
case <-timer.C:

‎pkg/gce-cloud-provider/compute/gce.go

+6-6
Original file line numberDiff line numberDiff line change
@@ -76,7 +76,7 @@ func CreateCloudProvider(vendorVersion string, configPath string) (*CloudProvide
7676
// At this point configFile could still be nil.
7777
// Any following code that uses configFile should handle nil pointer gracefully.
7878

79-
klog.V(1).Infof("Using GCE provider config %+v", configFile)
79+
klog.V(2).Infof("Using GCE provider config %+v", configFile)
8080

8181
tokenSource, err := generateTokenSource(configFile)
8282
if err != nil {
@@ -109,7 +109,7 @@ func generateTokenSource(configFile *ConfigFile) (oauth2.TokenSource, error) {
109109
// Use AltTokenSource
110110

111111
tokenSource := NewAltTokenSource(configFile.Global.TokenURL, configFile.Global.TokenBody)
112-
klog.V(4).Infof("Using AltTokenSource %#v", tokenSource)
112+
klog.V(2).Infof("Using AltTokenSource %#v", tokenSource)
113113
return tokenSource, nil
114114
}
115115

@@ -122,11 +122,11 @@ func generateTokenSource(configFile *ConfigFile) (oauth2.TokenSource, error) {
122122

123123
// DefaultTokenSource relies on GOOGLE_APPLICATION_CREDENTIALS env var being set.
124124
if gac, ok := os.LookupEnv("GOOGLE_APPLICATION_CREDENTIALS"); ok {
125-
klog.V(4).Infof("GOOGLE_APPLICATION_CREDENTIALS env var set %v", gac)
125+
klog.V(2).Infof("GOOGLE_APPLICATION_CREDENTIALS env var set %v", gac)
126126
} else {
127127
klog.Warningf("GOOGLE_APPLICATION_CREDENTIALS env var not set")
128128
}
129-
klog.V(4).Infof("Using DefaultTokenSource %#v", tokenSource)
129+
klog.V(2).Infof("Using DefaultTokenSource %#v", tokenSource)
130130

131131
return tokenSource, err
132132
}
@@ -198,10 +198,10 @@ func getProjectAndZone(config *ConfigFile) (string, string, error) {
198198
if err != nil {
199199
return "", "", err
200200
}
201-
klog.V(4).Infof("Using GCP project ID from the Metadata server: %q", projectID)
201+
klog.V(2).Infof("Using GCP project ID from the Metadata server: %q", projectID)
202202
} else {
203203
projectID = config.Global.ProjectId
204-
klog.V(4).Infof("Using GCP project ID from the local GCE cloud provider config file: %q", projectID)
204+
klog.V(2).Infof("Using GCP project ID from the local GCE cloud provider config file: %q", projectID)
205205
}
206206

207207
return projectID, zone, nil

0 commit comments

Comments
 (0)