Skip to content
This repository has been archived by the owner on Nov 26, 2024. It is now read-only.

Latest commit

 

History

History
70 lines (61 loc) · 8.13 KB

distinguish_logs_by_thread_ID_in_cpi_ng.md

File metadata and controls

70 lines (61 loc) · 8.13 KB

Distinguish logs by thread ID

Motivation

The log format is [packageName] date time message in the current CPI. It is difficult to track and locate problems in CPI log file when multi-actions execute at the same time. For example A log snippet is below. There were 3 'create_vm' actions running and it was difficult to distinguish their process.

[softlayerGo] 2017/11/27 06:48:08 [DEBUG] Request URL:  GET https://api.softlayer.com/rest/v3.1/SoftLayer_Virtual_Guest_Block_Device_Template_Group/22345678.json?objectMask=mask%5Bid%2C+name%2C+globalIdentifier%2C+imageType%2C+accountId%5D
[softlayerGo] 2017/11/27 06:48:08 [DEBUG] Parameters:
[softlayerGo] 2017/11/27 06:48:09 [DEBUG] Response:  {"accountId":1234567,"id":22345678,"name":"light-bosh-stemcell-3468.11-softlayer-xen-ubuntu-trusty-go_agent","globalIdentifier":"557ba6ac-6e5d-4052-bb9f-a732067bdefc","imageType":{"description":"a disk that may be replaced on upgrade","keyName":"SYSTEM","name":"System"}}
[softlayerGo] 2017/11/27 06:48:09 [DEBUG] Request URL:  GET https://api.softlayer.com/rest/v3.1/SoftLayer_Network_Vlan/32345678.json?objectMask=mask%5Bid%2CprimarySubnetId%2CnetworkSpace%5D
[softlayerGo] 2017/11/27 06:48:09 [DEBUG] Parameters:
[softlayerGo] 2017/11/27 06:48:09 [DEBUG] Response:  {"accountId":1234567,"id":22345678,"name":"light-bosh-stemcell-3468.11-softlayer-xen-ubuntu-trusty-go_agent","globalIdentifier":"557ba6ac-6e5d-4052-bb9f-a732067bdefc","imageType":{"description":"a disk that may be replaced on upgrade","keyName":"SYSTEM","name":"System"}}
[softlayerGo] 2017/11/27 06:48:09 [DEBUG] Request URL:  GET https://api.softlayer.com/rest/v3.1/SoftLayer_Network_Vlan/42345678.json?objectMask=mask%5Bid%2CprimarySubnetId%2CnetworkSpace%5D
[softlayerGo] 2017/11/27 06:48:09 [DEBUG] Parameters:
[softlayerGo] 2017/11/27 06:48:09 [DEBUG] Response:  {"accountId":1234567,"id":22345678,"name":"light-bosh-stemcell-3468.11-softlayer-xen-ubuntu-trusty-go_agent","globalIdentifier":"557ba6ac-6e5d-4052-bb9f-a732067bdefc","imageType":{"description":"a disk that may be replaced on upgrade","keyName":"SYSTEM","name":"System"}}
[softlayerGo] 2017/11/27 06:48:09 [DEBUG] Request URL:  GET https://api.softlayer.com/rest/v3.1/SoftLayer_Network_Vlan/42345678.json?objectMask=mask%5Bid%2CprimarySubnetId%2CnetworkSpace%5D
[softlayerGo] 2017/11/27 06:48:09 [DEBUG] Parameters:
[softlayerGo] 2017/11/27 06:48:10 [DEBUG] Response:  {"id":42345678,"primarySubnetId":52345678,"networkSpace":"PUBLIC"}
[softlayerGo] 2017/11/27 06:48:10 [DEBUG] Request URL:  GET https://api.softlayer.com/rest/v3.1/SoftLayer_Network_Vlan/62345678.json?objectMask=mask%5Bid%2CprimarySubnetId%2CnetworkSpace%5D
[softlayerGo] 2017/11/27 06:48:10 [DEBUG] Parameters:
[softlayerGo] 2017/11/27 06:48:10 [DEBUG] Response:  {"id":42345678,"primarySubnetId":52345678,"networkSpace":"PUBLIC"}
[softlayerGo] 2017/11/27 06:48:10 [DEBUG] Request URL:  GET https://api.softlayer.com/rest/v3.1/SoftLayer_Network_Vlan/62345678.json?objectMask=mask%5Bid%2CprimarySubnetId%2CnetworkSpace%5D
[softlayerGo] 2017/11/27 06:48:10 [DEBUG] Parameters:
[softlayerGo] 2017/11/27 06:48:10 [DEBUG] Response:  {"id":32345678,"primarySubnetId":62345678,"networkSpace":"PRIVATE"}
[softlayerGo] 2017/11/27 06:48:10 [DEBUG] Request URL:  POST https://api.softlayer.com/rest/v3.1/SoftLayer_Virtual_Guest.json

The softlayer CPI supports a function to distinguish every actions by thread id.

Details

The thread_id was generated in 9 digits when invoke cpi action and added to the log prefix. So the log format in softlayer_ng is [thread_id:packageName] date time message. So it could be used to distinguish in each actions. For example, in this picture, some logs could be gathered by the number beginning with 9383 in a ‘create_vm’ action. We can get rid of logs generated by others actions.

[938349194:softlayerGo] 2017/11/27 06:48:08 [DEBUG] Request URL:  GET https://api.softlayer.com/rest/v3.1/SoftLayer_Virtual_Guest_Block_Device_Template_Group/22345678.json?objectMask=mask%5Bid%2C+name%2C+globalIdentifier%2C+imageType%2C+accountId%5D
[938349194:softlayerGo] 2017/11/27 06:48:08 [DEBUG] Parameters:
[810766244:softlayerGo] 2017/11/27 06:48:09 [DEBUG] Response:  {"accountId":12345678,"id":22345678,"name":"light-bosh-stemcell-3468.11-softlayer-xen-ubuntu-trusty-go_agent","globalIdentifier":"557ba6ac-6e5d-4052-bb9f-a732067bdefc","imageType":{"description":"a disk that may be replaced on upgrade","keyName":"SYSTEM","name":"System"}}
[810766244:softlayerGo] 2017/11/27 06:48:09 [DEBUG] Request URL:  GET https://api.softlayer.com/rest/v3.1/SoftLayer_Network_Vlan/32345678.json?objectMask=mask%5Bid%2CprimarySubnetId%2CnetworkSpace%5D
[810766244:softlayerGo] 2017/11/27 06:48:09 [DEBUG] Parameters:
[906216319:softlayerGo] 2017/11/27 06:48:09 [DEBUG] Response:  {"accountId":12345678,"id":22345678,"name":"light-bosh-stemcell-3468.11-softlayer-xen-ubuntu-trusty-go_agent","globalIdentifier":"557ba6ac-6e5d-4052-bb9f-a732067bdefc","imageType":{"description":"a disk that may be replaced on upgrade","keyName":"SYSTEM","name":"System"}}
[906216319:softlayerGo] 2017/11/27 06:48:09 [DEBUG] Request URL:  GET https://api.softlayer.com/rest/v3.1/SoftLayer_Network_Vlan/42345678.json?objectMask=mask%5Bid%2CprimarySubnetId%2CnetworkSpace%5D
[906216319:softlayerGo] 2017/11/27 06:48:09 [DEBUG] Parameters:
[938349194:softlayerGo] 2017/11/27 06:48:09 [DEBUG] Response:  {"accountId":12345678,"id":22345678,"name":"light-bosh-stemcell-3468.11-softlayer-xen-ubuntu-trusty-go_agent","globalIdentifier":"557ba6ac-6e5d-4052-bb9f-a732067bdefc","imageType":{"description":"a disk that may be replaced on upgrade","keyName":"SYSTEM","name":"System"}}
[938349194:softlayerGo] 2017/11/27 06:48:09 [DEBUG] Request URL:  GET https://api.softlayer.com/rest/v3.1/SoftLayer_Network_Vlan/42345678.json?objectMask=mask%5Bid%2CprimarySubnetId%2CnetworkSpace%5D
[938349194:softlayerGo] 2017/11/27 06:48:09 [DEBUG] Parameters:
[938349194:softlayerGo] 2017/11/27 06:48:10 [DEBUG] Response:  {"id":42345678,"primarySubnetId":52345678,"networkSpace":"PUBLIC"}
[938349194:softlayerGo] 2017/11/27 06:48:10 [DEBUG] Request URL:  GET https://api.softlayer.com/rest/v3.1/SoftLayer_Network_Vlan/62345678.json?objectMask=mask%5Bid%2CprimarySubnetId%2CnetworkSpace%5D
[938349194:softlayerGo] 2017/11/27 06:48:10 [DEBUG] Parameters:
[906216319:softlayerGo] 2017/11/27 06:48:10 [DEBUG] Response:  {"id":42345678,"primarySubnetId":52345678,"networkSpace":"PUBLIC"}
[906216319:softlayerGo] 2017/11/27 06:48:10 [DEBUG] Request URL:  GET https://api.softlayer.com/rest/v3.1/SoftLayer_Network_Vlan/62345678.json?objectMask=mask%5Bid%2CprimarySubnetId%2CnetworkSpace%5D
[906216319:softlayerGo] 2017/11/27 06:48:10 [DEBUG] Parameters:
[810766244:softlayerGo] 2017/11/27 06:48:10 [DEBUG] Response:  {"id":32345678,"primarySubnetId":72345678,"networkSpace":"PRIVATE"}

And we could use grep -nr cpi.stderr.log -e 938349194 > 938349194.log to get the specified CPI execution log.

1:[938349194:softlayerGo] 2017/11/27 06:48:08 [DEBUG] Request URL:  GET https://api.softlayer.com/rest/v3.1/SoftLayer_Virtual_Guest_Block_Device_Template_Group/22345678.json?objectMask=mask%5Bid%2C+name%2C+globalIdentifier%2C+imageType%2C+accountId%5D
2:[938349194:softlayerGo] 2017/11/27 06:48:08 [DEBUG] Parameters:
9:[938349194:softlayerGo] 2017/11/27 06:48:09 [DEBUG] Response:  {"accountId":12345678,"id":22345678,"name":"light-bosh-stemcell-3468.11-softlayer-xen-ubuntu-trusty-go_agent","globalIdentifier":"557ba6ac-6e5d-4052-bb9f-a732067bdefc","imageType":{"description":"a disk that may be replaced on upgrade","keyName":"SYSTEM","name":"System"}}
10:[938349194:softlayerGo] 2017/11/27 06:48:09 [DEBUG] Request URL:  GET https://api.softlayer.com/rest/v3.1/SoftLayer_Network_Vlan/42345678.json?objectMask=mask%5Bid%2CprimarySubnetId%2CnetworkSpace%5D
11:[938349194:softlayerGo] 2017/11/27 06:48:09 [DEBUG] Parameters:
12:[938349194:softlayerGo] 2017/11/27 06:48:10 [DEBUG] Response:  {"id":42345678,"primarySubnetId":52345678,"networkSpace":"PUBLIC"}
13:[938349194:softlayerGo] 2017/11/27 06:48:10 [DEBUG] Request URL:  GET https://api.softlayer.com/rest/v3.1/SoftLayer_Network_Vlan/62345678.json?objectMask=mask%5Bid%2CprimarySubnetId%2CnetworkSpace%5D
14:[938349194:softlayerGo] 2017/11/27 06:48:10 [DEBUG] Parameters: