Heka Debugging

Heka Debugging

From time to time something went wrong with any software so there are a few words about debugging.

Save data to file

The easiest way to debug is to configure FileOutput (https://hekad.readthedocs.org/en/v0.10.0/config/outputs/file.html) and save all data in debug file.
To encode output is used RstEncoder (https://hekad.readthedocs.org/en/v0.10.0/config/encoders/rst.html)

To enable such debugging it is necessary to add config file, e.g /etc/lma_collector/00_debug.toml
Attention: this configuration is dangerous because it will create I/O load. Please be careful with debugging on production!

[RstEncoder]

[output_file]
type = "FileOutput"
message_matcher = "Fields[aggregator] == NIL"
path = "/var/log/heka-debug.log"
perm = "666"
flush_count = 100
flush_operator = "OR"
encoder = "RstEncoder"

Example of output:

tail -100 /var/log/heka-debug.log
... <SKIP> ...
:Timestamp: 2016-01-31 16:58:42.232999936 +0000 UTC
:Type: metric
:Hostname: node-6
:Pid: 5505
:Uuid: 2a73fa6f-21fc-40b0-acf9-7fe96bcb9b80
:Logger: collectd
:Payload: {"type":"gauge","values":[0],"type_instance":"q-agent-notifier-dvr-update_fanout_57e5b132e51840ebb6.messages","meta":{"0":true},"dsnames":["value"],"plugin":"rabbitmq_info","time":1454259522.233,"interval":10,"host":"node-6","dstypes":["gauge"],"plugin_instance":""}
:EnvVersion:
:Severity: 6
:Fields:
    | name:"type" type:string value:"gauge"
    | name:"source" type:string value:"rabbitmq_info"
    | name:"openstack_release" type:string value:"2015.1.0-7.0"
    | name:"deployment_mode" type:string value:"ha_compact"
    | name:"openstack_roles" type:string value:"primary-controller"
    | name:"queue" type:string value:"q-agent-notifier-dvr-update_fanout_57e5b132e51840ebb6"
    | name:"tag_fields" type:string value:"queue"
    | name:"openstack_region" type:string value:"RegionOne"
    | name:"name" type:string value:"rabbitmq_queue_messages"
    | name:"hostname" type:string value:"node-6"
    | name:"value" type:double value:0
    | name:"deployment_id" type:string value:"3"
    | name:"environment_label" type:string value:"test2"
    | name:"interval" type:double value:10


:Timestamp: 2016-01-31 16:58:42 +0000 UTC
:Type: test_decoder
:Hostname: node-6
:Pid: 0
:Uuid: bbc94442-67c8-4445-acf8-341b14c2d43f
:Logger: test_input
:Payload:
:EnvVersion:
:Severity: 7
:Fields:
    | name:"test_decoderData" type:string value:"888999888"
    | name:"test_decoderCount" type:double value:1212
    | name:"test_decoderDataToNumber" type:double value:8.88999888e+08


:Timestamp: 2016-01-31 16:58:42 +0000 UTC
:Type: log
:Hostname: node-6
:Pid: 11905
:Uuid: 36cfae57-cb3e-4777-a886-60a351fb230c
:Logger: pacemaker
:Payload: cib_process_ping: 	Reporting our current digest to node-6.domain.tld: 70954c66c71f324b3851af4d92ef93dd for 0.90.152 (0x1c12960 0)

:EnvVersion:
:Severity: 7
:Fields:
    | name:"deployment_mode" type:string value:"ha_compact"
    | name:"environment_label" type:string value:"test2"
    | name:"openstack_region" type:string value:"RegionOne"
    | name:"deployment_id" type:string value:"3"
    | name:"severity_label" type:string value:"DEBUG"
    | name:"programname" type:string value:"cib"
    | name:"openstack_roles" type:string value:"primary-controller"
    | name:"openstack_release" type:string value:"2015.1.0-7.0"

Debug data filtering

To avoid I/O overload if is possible to filter messages. To filter data only from test_decoder and save it into the /var/log/heka-debug-test-decoder.log file is used the following configuration:

01_debug_test_decoder_data.toml

[output_file]
type = "FileOutput"
message_matcher = "Type == 'test_decoder'"
path = "/var/log/heka-debug-test-decoder.log"
perm = "666"
flush_count = 100
flush_operator = "OR"
encoder = "RstEncoder"

Remark: depends on your current Heka configuration you may need to enable RstEncoder. In this example it is already enabled in 00_debug.toml file.

Example of output:

:Timestamp: 2016-01-31 17:07:16 +0000 UTC
:Type: test_decoder
:Hostname: node-6
:Pid: 0
:Uuid: 38ffa77b-8f5c-4f73-aba5-f5de1f15f0b8
:Logger: test_input
:Payload:
:EnvVersion:
:Severity: 7
:Fields:
    | name:"test_decoderData" type:string value:"888999888"
    | name:"test_decoderCount" type:double value:29
    | name:"test_decoderDataToNumber" type:double value:8.88999888e+08


:Timestamp: 2016-01-31 17:07:17 +0000 UTC
:Type: test_decoder
:Hostname: node-6
:Pid: 0
:Uuid: 1545163c-cc97-46aa-aba8-431ab6ca3338
:Logger: test_input
:Payload:
:EnvVersion:
:Severity: 7
:Fields:
    | name:"test_decoderData" type:string value:"888999888"
    | name:"test_decoderCount" type:double value:30
    | name:"test_decoderDataToNumber" type:double value:8.88999888e+08


:Timestamp: 2016-01-31 17:07:18 +0000 UTC
:Type: test_decoder
:Hostname: node-6
:Pid: 0
:Uuid: 5da75795-63fd-48f8-ac52-44db368f54ed
:Logger: test_input
:Payload:
:EnvVersion:
:Severity: 7
:Fields:
    | name:"test_decoderData" type:string value:"888999888"
    | name:"test_decoderCount" type:double value:31
    | name:"test_decoderDataToNumber" type:double value:8.88999888e+08

If Heka can't start

If Heka is not able to start it is possible to run it manually:

• Disable resorce in CRM

1. Run crm resource command:

#crm resource crm(live)resource# list ... <SKIP> ... Clone Set: clone_lma_collector [lma_collector] Started: [ node-6.domain.tld ]

1. Stop lma_ollector resource:

#crm(live)resource# stop lma_collector crm(live)resource# stop clone_lma_collector

1. Check lma_collector resource status. It should be stopped.

#crm(live)resource# list Clone Set: clone_lma_collector [lma_collector] Stopped: [ node-6.domain.tld ]