Unable to send Smart Call Home messages via email

[viawest.net]

Hello everyone,

We have started deploying SCH using HTTP reporting back to a TG for some of our devices. But due to the number of quirks across so many different versions of hardware/software, we are looking into email reporting - hoping that will let us use the same method across all devices.

I am testing on a Nexus 5672UP running 7.1(4)N1(1). Running the command 'callhome test inventory' - debugging on the firewall shows no traffic being sent at all. HTTP alerts work, but we have to use the default profile "CiscoTAC-1" for some reason. I've noticed that on some other Nexus devices as well. If I telnet to the SMTP server on port 25 I get a response.

Here are the configs:

callhome
contract-id XXXXXXX
email-contact XXXXXXX
phone-contact XXXXXXX
streetaddress XXXXXXX
destination-profile CiscoTAC-1 message-size 2500000
destination-profile test
destination-profile test format XML
destination-profile test message-size 2500000
destination-profile test email-addr XXXXXXX
destination-profile test alert-group All
transport email smtp-server XXXXXXX port 25
transport email from XXXXXXX
transport email reply-to XXXXXXX
enable
periodic-inventory notification interval 30

Here is the debug output from "debug callhome all". I changed my SMTP server IP to "$smtpServerIp" in the output:

callhome: Src: 0x00000101/54670 Dst: 0x00000101/0 ID: 0x08ED5A58 Size: 2740 [REQ] Opc: 2157 (MTS_OPC_CALLHOME_TEST) RR: 0x08ED5A58 HA_SEQNO: 0x00000000 TS: 0xF9B5747131C28 REJ:0 SYNC:1 OPTIONS:0x0
<<< HEX DATA REMOVED >>>
callhome: In can_process_message for alert inventory
callhome: alert inventory exists in the alert table
callhome: Updated the message sent count for alert inventory to 18
callhome: filling in time field with 2017-02-02 07:19:09 GMT-07:00
callhome: filling in subtype, type fields with inventory
callhome: inventory message
callhome: appending type nvp
callhome: appending subtype nvp
callhome: filling in the header list
callhome: filling up the chassis list
callhome: filling up the main body list
callhome: filling up the fru list
callhome: Entering function do_event_correlation
callhome: getting dest profiles for alert group test
callhome: getting dest profiles for alert group cisco-tac
callhome: dest_profile_id full_txt added to final list
callhome: dest_profile_id short_txt added to final list
callhome: dest_profile_id test added to final list
callhome: dest_profile_id CiscoTAC-1 added to final list
callhome: Value of is_storage_vdc is #0#
callhome: event rule id value : #nexus_cli_command#
callhome: event rule id value : #nexus_cli_command#
callhome: event rule id value : #alert_group#
callhome: event rule id value : #alert_group#
callhome: event rule id value : #level#
callhome: event rule id value : #nexus_cli_command#
callhome: event rule id value : #nexus_cli_command#
callhome: event rule id value : #mds_cli_command#
callhome: event rule id value : #mds_cli_command#
callhome: Applying the event rule for destination profile full_txt
callhome: alert group for profile : full_txt is : all
callhome: Applying the event rule for destination profile short_txt
callhome: alert group for profile : short_txt is : all
callhome: Applying the event rule for destination profile test
callhome: alert group for profile : test is : all
callhome: Applying the event rule for destination profile CiscoTAC-1
callhome: Exiting function do_event_correlation
callhome: Entering build_event_notification_payload
callhome: key : Name value : 85344_crsw01.den03
callhome: key : EventTime value : 2017-02-02 07:19:09 GMT-07:00
callhome: key : MessageDescription value : inventory ^\f▒w^O
callhome: message level: 2
callhome: Exiting build_event_notification_payload
callhome: Entering send_snmp_event_notification
callhome: Exiting send_snmp_event_notification
callhome: running cli commands for alert name : inventory, message id : 855636226
callhome: In function schedule_procjob for msg_id: 855636226, alert: inventory
callhome: calling procjob_fork for msg_id: 855636226, alert: inventory
callhome: Callhome handle 23346 added to procjob list
callhome: process scheduled for running cli commands for alert inventory, message id 855636226 ,
callhome: Not Internally generated message
callhome: Added node to the process list with alert name : inventory, message id : 855636226
callhome: No of elements in the process list is 1
callhome: Src: 0x00000101/66 Dst: 0x00000101/54670 ID: 0x08ED5A5E Size: 2740 [RSP] Opc: 2157 (MTS_OPC_CALLHOME_TEST) RR: 0x08ED5A58 HA_SEQNO: 0x00000000 TS: 0xF9B5747C8C568 REJ:0 SYNC:1 OPTIONS:0x0
<<< HEX DATA REMOVED >>>
callhome: Src: 0x00000101/54672 Dst: 0x00000101/66 ID: 0x08ED5A62 Size: 12 [REQ] Opc: 7601 (MTS_OPC_PROCJOB_WAIT_TO_SPAWN_JOB) RR: 0x08ED5A62 HA_SEQNO: 0x00000000 TS: 0xF9B5747DA53C0 REJ:0 SYNC:0 OPTIONS:0x0
callhome: 00 00 5B 32 68 4A 48 1A 00 00 00 01
callhome: Entering run_cli_commands for alert: inventory
callhome: Entering run_cli_commands for alert: inventory, msg_size : 2156, msg_id :49938226,
callhome: CLI_CMD_LIST is !NULL
callhome: executing command:/isan/bin/vsh -c "show vdc membership" -e 0 -q 2 -o 0 | head --bytes=250000
callhome: Using VRF: default
callhome: executing command:/isan/bin/vsh -c "show vdc current-vdc" -e 0 -q 2 -o 0 | head --bytes=250000
callhome: Using VRF: default
callhome: executing command:/isan/bin/vsh -c "show module" -e 0 -q 2 -o 0 | head --bytes=250000
callhome: Using VRF: default
callhome: executing command:/isan/bin/vsh -c "show version" -e 0 -q 2 -o 0 | head --bytes=250000
callhome: Using VRF: default
callhome: Src: 0x00000101/54672 Dst: 0x00000101/66 ID: 0x08ED5BE2 Size: 5244 [REQ] Opc: 7602 (MTS_OPC_PROCJOB_JOB_DONE) RR: 0x08ED5BE2 HA_SEQNO: 0x00000000 TS: 0xF9B57F10419BE REJ:0 SYNC:0 OPTIONS:0x0
<<< HEX DATA REMOVED >>>
callhome: procjobcb_job_done: Handle 23346 syserr "SUCCESS" ret_info_size 5228 ret_syserr 0 ret_info 77f4fe60
callhome: procjob callback called for alert : inventory, message id : 49938226, with procjob handle 23346
callhome: Found procjob handle 23346 with msg_id 855636226
callhome: Callback called for alert : inventory, message id : 49938226 with procjob handle 23346
callhome: Number of entries in cli_cmd_list: 4
callhome: cli command = show vdc membership, cli output file = /dev/shm/callhome.d/workspace//cli_outputVbd9Cu
callhome: cli command = show vdc current-vdc, cli output file = /dev/shm/callhome.d/workspace//cli_outputLNCzkX
callhome: cli command = show module, cli output file = /dev/shm/callhome.d/workspace//cli_output7fFI3F
callhome: cli command = show version, cli output file = /dev/shm/callhome.d/workspace//cli_outputMUIxMH
callhome: Formatting the message for alert : inventory, message id : 855636226
callhome: In function format_and_send_callhome_mesg for alert: inventory, msg_id 855636226
callhome: Procesing for MTS message 1
callhome: In function format_and_send_for_each for msg_id 855636226
callhome: format called for transport method 1, msg_id 855636226, destination_profile full_txt
callhome: executing command:gzip /dev/shm/callhome.d/workspace//workspaceyS0NDc/formatted_message
callhome: executing command:gzip /dev/shm/callhome.d/workspace//workspaceyS0NDc/formatted_message
callhome: Update the zipped file path to /dev/shm/callhome.d/workspace//workspaceyS0NDc/formatted_message.gz
callhome: called for transport method 1 , msg_id 855636226, destination_profile full_txt
callhome: IN transport_callhome_mesg
callhome: Destination profile full_txt
callhome: IN send_callhome_email_mesg with msg_id :855636226
callhome: executing command:mv /dev/shm/callhome.d/workspace//workspaceyS0NDc /callhome/spool//1GyXU8
callhome: Opened:/callhome/spool//1GyXU8/script
callhome: no email address configured for destination profile:full_txt
callhome: problem in creating the email script for destination profile:full_txt
callhome: In cleanup_spool:
callhome: executing command:rm -rf /callhome/spool//1GyXU8
callhome: the process status of my_system is 0
callhome: In cleanup_spool:
callhome: executing command:rm -rf /callhome/spool//1GyXU8
callhome: the process status of my_system is 0
callhome: retcode[0] 23 : retcode[1] 1077608463
callhome: problem in transporting the message Could send message; transport methods failed
callhome: format called for transport method 1, msg_id 855636226, destination_profile short_txt
callhome: executing command:gzip /dev/shm/callhome.d/workspace//workspace8pLiEb/formatted_message
callhome: executing command:gzip /dev/shm/callhome.d/workspace//workspace8pLiEb/formatted_message
callhome: Update the zipped file path to /dev/shm/callhome.d/workspace//workspace8pLiEb/formatted_message.gz
callhome: called for transport method 1 , msg_id 855636226, destination_profile short_txt
callhome: IN transport_callhome_mesg
callhome: Destination profile short_txt
callhome: IN send_callhome_email_mesg with msg_id :855636226
callhome: executing command:mv /dev/shm/callhome.d/workspace//workspace8pLiEb /callhome/spool//BqTVOg
callhome: Opened:/callhome/spool//BqTVOg/script
callhome: no email address configured for destination profile:short_txt
callhome: problem in creating the email script for destination profile:short_txt
callhome: In cleanup_spool:
callhome: executing command:rm -rf /callhome/spool//BqTVOg
callhome: the process status of my_system is 0
callhome: In cleanup_spool:
callhome: executing command:rm -rf /callhome/spool//BqTVOg
callhome: the process status of my_system is 0
callhome: retcode[0] 23 : retcode[1] 1077608463
callhome: problem in transporting the message Could send message; transport methods failedCould send message; transport methods failed
callhome: format called for transport method 1, msg_id 855636226, destination_profile test
callhome: callhoem alert : inventory
callhome: AML_TAG_CONTACT_EMAIL[[
callhome: ch:SystemInfo[[
callhome: before attachment in aml block
callhome: xml formatter end
callhome: executing command:gzip /dev/shm/callhome.d/workspace//workspacerZS0Si/formatted_message
callhome: executing command:gzip /dev/shm/callhome.d/workspace//workspacerZS0Si/formatted_message
callhome: Update the zipped file path to /dev/shm/callhome.d/workspace//workspacerZS0Si/formatted_message.gz
callhome: called for transport method 1 , msg_id 855636226, destination_profile test
callhome: IN transport_callhome_mesg
callhome: Destination profile test
callhome: IN send_callhome_email_mesg with msg_id :855636226
callhome: executing command:mv /dev/shm/callhome.d/workspace//workspacerZS0Si /callhome/spool//3qYKum
callhome: Opened:/callhome/spool//3qYKum/script
callhome: In function schedule_procjob for msg_id: 855636226, alert: inventory
callhome: calling procjob_fork for msg_id: 855636226, alert: inventory
callhome: Callhome handle 23394 added to procjob list
callhome: retcode[0] 23 : retcode[1] 0
callhome: EXIT transport_callhome_mesg
callhome: format_and_send successfull for transport method 1 , msg_id 855636226, destination_profile test
callhome: format called for transport method 1, msg_id 855636226, destination_profile CiscoTAC-1
callhome: callhoem alert : inventory
callhome: AML_TAG_CONTACT_EMAIL[[
callhome: ch:SystemInfo[[
callhome: before attachment in aml block
callhome: xml formatter end
callhome: executing command:gzip /dev/shm/callhome.d/workspace//workspacevrWwCs/formatted_message
callhome: executing command:gzip /dev/shm/callhome.d/workspace//workspacevrWwCs/formatted_message
callhome: Update the zipped file path to /dev/shm/callhome.d/workspace//workspacevrWwCs/formatted_message.gz
callhome: called for transport method 1 , msg_id 855636226, destination_profile CiscoTAC-1
callhome: IN transport_callhome_mesg
callhome: Destination profile CiscoTAC-1
callhome: IN send_callhome_email_mesg with msg_id :855636226
callhome: executing command:mv /dev/shm/callhome.d/workspace//workspacevrWwCs /callhome/spool//nVga8A
callhome: Opened:/callhome/spool//nVga8A/script
callhome: no email address configured for destination profile:CiscoTAC-1
callhome: problem in creating the email script for destination profile:CiscoTAC-1
callhome: In cleanup_spool:
callhome: executing command:rm -rf /callhome/spool//nVga8A
callhome: the process status of my_system is 0
callhome: In cleanup_spool:
callhome: executing command:rm -rf /callhome/spool//nVga8A
callhome: the process status of my_system is 0
callhome: retcode[0] 23 : retcode[1] 1077608463
callhome: problem in transporting the message Could send message; transport methods failedCould send message; transport methods failedCould send message; transport methods failed
callhome: At least one message sent successfully
callhome: Exiting send_callhome_mesg
callhome: Successfully formatted and sent the message for alert : inventory, message id : 855636226
callhome: Sending the message for alert : inventory, message id : 855636226
callhome: Src: 0x00000101/54694 Dst: 0x00000101/66 ID: 0x08ED5C07 Size: 12 [REQ] Opc: 7601 (MTS_OPC_PROCJOB_WAIT_TO_SPAWN_JOB) RR: 0x08ED5C07 HA_SEQNO: 0x00000000 TS: 0xF9B5812D72572 REJ:0 SYNC:0 OPTIONS:0x0
callhome: 00 00 5B 62 74 9A BB 43 00 00 00 01
callhome: IN dispatch_callhome_mesg with msg_id 855636226
callhome: executing command:/callhome/spool//3qYKum/script
callhome: Using VRF: default
callhome: smtpclient exit status 1
callhome: <Thu Feb 2 07:19:11 2017> <4> <Thu Feb 2 07:19:11 2017> <4> Command line arguments (0): <Thu Feb 2 07:19:11 2017> <4> Environment variables: <Thu Feb 2 07:19:11 2017> <4> ^I0: SYSMGR_RECOVERY_CFG_DIR= <Thu Feb 2 07:19:11 2017> <4> ^I1: SYSMGR_VDC_SRV_TYPE=52 <Thu Fe
callhome: smtp failure
callhome: email message for profile test
callhome: SMTPclient: In ZULU_CA Code
callhome: SMTPclient: get addr info inputs : mailhost:$smtpServerIp,port:2146966069
callhome: SMTPclient: Host:$smtpServerIp:socket: Invalid argument
callhome: In cleanup_spool:
callhome: executing command:rm -rf /callhome/spool//3qYKum
callhome: the process status of my_system is 0
callhome: Exiting dispatch_callhome_mesg ret_val :0
callhome: Src: 0x00000101/54694 Dst: 0x00000101/66 ID: 0x08ED5C10 Size: 2136 [REQ] Opc: 7602 (MTS_OPC_PROCJOB_JOB_DONE) RR: 0x08ED5C10 HA_SEQNO: 0x00000000 TS: 0xF9B582C59D08E REJ:0 SYNC:0 OPTIONS:0x0
<<< HEX DATA REMOVED >>>
callhome: procjobcb_job_done: Handle 23394 syserr "SUCCESS" ret_info_size 2120 ret_syserr 0 ret_info 77f4fe60
callhome: procjob callback called for alert : inventory, message id : 49938226, with procjob handle 23394
callhome: Found procjob handle 23394 with msg_id 855636226
callhome: IN CALLHOME_SEND_EMAIL
callhome: problem in transporting the message Error in transporting email message for test SMTPclient: Num of SMTP Servers: 0: Server Name: $smtpServerIp SMTPclient: Port Number : 2146966069 SMTPclient: In ZULU_CA Code SMTPclient: get addr info inputs : mailhost:$smtpServerIp,port:2146
callhome: Entering send_alert_message_send_failure_notification with error code - 1077608457
callhome: mts_send for smtp msg send fail - successfull
callhome: Exiting send_alert_message_send_failure_notification
callhome: Unable to send callhome message for alert : inventory, message id : 855636226
callhome: Could send message; transport methods failedCould send message; transport methods failedCould send message; transport methods failedError in transporting email message for test SMTPclient: Num of SMTP Servers: 0: Server Name: $smtpServerIp SMTPclient: Port Number : 2146966
callhome: setting error code for last callhome message to 1077608465
callhome: No of elements in the process list is 0
callhome: entered into inv_msg_send() function
callhome: in inv_msg_send() current time 7 hours and 19 minutes
callhome: periodic inv counter-- 1495 before increment
callhome: periodic inv counter-- 1496 after increment
callhome: entered into inv_msg_send() function
callhome: in inv_msg_send() current time 7 hours and 20 minutes
callhome: periodic inv counter-- 1496 before increment
callhome: periodic inv counter-- 1497 after increment
callhome: entered into inv_msg_send() function
callhome: in inv_msg_send() current time 7 hours and 21 minutes
callhome: periodic inv counter-- 1497 before increment
callhome: periodic inv counter-- 1498 after increment

Thanks!

[viawest.net]

Made some progress. I am able to get full text emails sent directly to myself. But I haven't configured the mail client on the TG yet, and not sure if it requires XML.

I had to do these two things:

1) Hard-set the "use-vrf" value for the email smtp-server:

transport email smtp-server $smtpServerIp port 25 use-vrf default

Even though the default VRF to use is "default" and the debug output above indicates it was using that.

2) Define an email address for the profile "full_txt" like so:

destination-profile full_txt email-addr person@company.com

Still not able to send XML emails, at least not using any of the "callhome test" commands.

[Pramod Srinivasa]

Hi ,

Is the configuration issue resolved ? If the issue is not resolved please raise a TAC case for further troubleshooting and getting the devices registered for SCH.

Please let me know if you need any assistance in raising the TAC case ?

Thanks,

Pramod