search

kamelnetworks / sonic-buildimage

Kamel Networks' pending patches to SONiC
https://dev.azure.com/kamelnetworks/sonic/_build?definitionId=5
Other
3 stars 1 forks source link

Telemetry's supervisord does not produce any logging #4

Open bluecmd opened 1 year ago

bluecmd commented 1 year ago

Starting telemetry's supervisord manually from inside the telemetry container, the following logging is reported:

May  1 14:07:53.981519 svc-kg-sw1 WARNING pmon#thermalctld: Failed to update thermal status for Temp_2 - KeyError(None)
May  1 14:07:53.982189 svc-kg-sw1 WARNING pmon#thermalctld: Failed to update thermal status for Temp_3 - KeyError(None)
May  1 14:07:54.145447 svc-kg-sw1 INFO dhclient[5823]: DHCPREQUEST for 10.199.100.218 on eth0 to 10.199.100.1 port 67
May  1 14:07:58.676885 svc-kg-sw1 INFO kernel: [ 4623.546342] perf: interrupt took too long (2519 > 2500), lowering kernel.perf_event_max_sample_rate to 79250
May  1 14:07:59.376948 svc-kg-sw1 INFO telemetry#supervisord 2023-05-01 14:07:59,375 INFO Included extra file "/etc/supervisor/conf.d/containercfgd.conf" during parsing
May  1 14:07:59.377661 svc-kg-sw1 INFO telemetry#supervisord 2023-05-01 14:07:59,376 INFO Included extra file "/etc/supervisor/conf.d/supervisord.conf" during parsing
May  1 14:07:59.377918 svc-kg-sw1 INFO telemetry#supervisord 2023-05-01 14:07:59,376 INFO Set uid to user 0 succeeded
May  1 14:07:59.389175 svc-kg-sw1 INFO telemetry#supervisord 2023-05-01 14:07:59,386 INFO RPC interface 'supervisor' initialized
May  1 14:07:59.389175 svc-kg-sw1 INFO telemetry#supervisord 2023-05-01 14:07:59,387 CRIT Server 'unix_http_server' running without any HTTP authentication checking
May  1 14:07:59.389175 svc-kg-sw1 INFO telemetry#supervisord 2023-05-01 14:07:59,387 INFO supervisord started with pid 1275
May  1 14:08:00.392848 svc-kg-sw1 INFO telemetry#supervisord 2023-05-01 14:08:00,391 INFO spawned: 'dependent-startup' with pid 1276
May  1 14:08:00.397789 svc-kg-sw1 INFO telemetry#supervisord 2023-05-01 14:08:00,396 INFO spawned: 'supervisor-proc-exit-listener' with pid 1277
May  1 14:08:01.914601 svc-kg-sw1 INFO telemetry#supervisord 2023-05-01 14:08:01,913 INFO success: dependent-startup entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
May  1 14:08:01.915549 svc-kg-sw1 INFO telemetry#supervisord 2023-05-01 14:08:01,914 INFO success: supervisor-proc-exit-listener entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
May  1 14:08:01.929752 svc-kg-sw1 INFO telemetry#supervisord 2023-05-01 14:08:01,928 INFO spawned: 'rsyslogd' with pid 1280
May  1 14:08:03.054709 svc-kg-sw1 INFO telemetry#supervisord 2023-05-01 14:08:03,053 INFO success: rsyslogd entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
May  1 14:08:04.086953 svc-kg-sw1 INFO telemetry#supervisord 2023-05-01 14:08:04,085 INFO spawned: 'start' with pid 1281
May  1 14:08:04.088633 svc-kg-sw1 INFO telemetry#supervisord 2023-05-01 14:08:04,087 INFO success: start entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
May  1 14:08:04.102951 svc-kg-sw1 INFO telemetry#supervisord 2023-05-01 14:08:04,100 INFO spawned: 'containercfgd' with pid 1282
May  1 14:08:04.113531 svc-kg-sw1 INFO telemetry#supervisord 2023-05-01 14:08:04,112 INFO exited: start (exit status 0; expected)
May  1 14:08:04.143113 svc-kg-sw1 INFO telemetry#supervisord 2023-05-01 14:08:04,141 INFO spawned: 'start' with pid 1284
May  1 14:08:04.143929 svc-kg-sw1 INFO telemetry#supervisord 2023-05-01 14:08:04,143 INFO success: start entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
May  1 14:08:04.170180 svc-kg-sw1 INFO telemetry#supervisord 2023-05-01 14:08:04,169 INFO exited: start (exit status 0; expected)
May  1 14:08:04.238264 svc-kg-sw1 INFO telemetry#supervisord 2023-05-01 14:08:04,237 INFO spawned: 'telemetry' with pid 1286
May  1 14:08:04.383844 svc-kg-sw1 NOTICE telemetry#containercfgd[1282]: Connected to CONFIG DB
May  1 14:08:04.388788 svc-kg-sw1 NOTICE telemetry#containercfgd[1282]: Syslog rate limit configuration does not change, ignore it
May  1 14:08:05.372721 svc-kg-sw1 INFO telemetry#supervisord 2023-05-01 14:08:05,367 INFO success: telemetry entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
May  1 14:08:05.372721 svc-kg-sw1 INFO telemetry#supervisord 2023-05-01 14:08:05,367 INFO success: containercfgd entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
May  1 14:08:05.558625 svc-kg-sw1 INFO memory_checker: [memory_checker] Exits without checking memory usage since container 'snmp' is not running!
May  1 14:08:06.146426 svc-kg-sw1 NOTICE telemetry#root: asdasdasd

Modification to /usr/bin/telemetry.sh inside telemetry container:

echo "I AM STDOUT" > /dev/stdout
echo "I AM STDERR" > /dev/stderr
logger asdasdasd
sleep 10
exec /usr/sbin/telemetry ${TELEMETRY_ARGS}

Notice that nothing is reported from stderr/stdout.

Manually running telemetry.sh:


root@svc-kg-sw1:/# telemetry.sh 
I AM STDOUT
I AM STDOUT
I AM STDERR
I0501 14:10:35.191974    1337 util.go:301] [CVL] : Current Values of CVL Configuration File map[LOGTOSTDERR:false LOG_FILE_SIZE:10485760 LOG_TO_FILE:false SKIP_SEMANTIC_VALIDATION:false SKIP_VALIDATION:false STDERRTHRESHOLD:ERROR TRACE_CACHE:false TRACE_CREATE:false TRACE_DELETE:false TRACE_LIBYANG:false TRACE_ONERROR:false TRACE_SEMANTIC:false TRACE_SYNTAX:false TRACE_UPDATE:false TRACE_YPARSER:false VERBOSITY:0 __comment1__:Set LOGTOSTDER to 'true' to log on standard error __comment2__:Display log upto INFO level __comment3__:Log to /tmp/cvl.log file __comment4__:Limit log file size in bytes, 0 means no limit, default 10MB __comment5__:Display log upto INFO level 8]
I0501 14:10:35.193657    1337 util.go:301] [CVL] : Current Values of CVL Configuration File map[LOGTOSTDERR:false LOG_FILE_SIZE:10485760 LOG_TO_FILE:false SKIP_SEMANTIC_VALIDATION:false SKIP_VALIDATION:false STDERRTHRESHOLD:ERROR TRACE_CACHE:false TRACE_CREATE:false TRACE_DELETE:false TRACE_LIBYANG:false TRACE_ONERROR:false TRACE_SEMANTIC:false TRACE_SYNTAX:false TRACE_UPDATE:false TRACE_YPARSER:false VERBOSITY:0 __comment1__:Set LOGTOSTDER to 'true' to log on standard error __comment2__:Display log upto INFO level __comment3__:Log to /tmp/cvl.log file __comment4__:Limit log file size in bytes, 0 means no limit, default 10MB __comment5__:Display log upto INFO level 8]
I0501 14:10:35.208416    1337 util.go:301] [CVL] : Could not read platform schema location or no platform specific schema exists. <nil>
W0501 14:10:35.208497    1337 util.go:303] [CVL] : [libyang Error] Schema node not found. (path: )
W0501 14:10:35.208525    1337 util.go:303] [CVL] : Unable to get schema details for sonic-common.yin
W0501 14:10:35.208560    1337 util.go:303] [CVL] : [libyang Error] Schema node not found. (path: )
W0501 14:10:35.208585    1337 util.go:303] [CVL] : Unable to get schema details for sonic-extension.yin
W0501 14:10:35.208696    1337 util.go:303] [CVL] : [libyang Error] Schema node not found. (path: )
W0501 14:10:35.208722    1337 util.go:303] [CVL] : Unable to get schema details for sonic-show-techsupport.yin
Yang modles path: /usr/models/yang/
Yang model List: [sonic-acl.yang sonic-common.yang sonic-extension.yang sonic-extensions.yang sonic-interface.yang sonic-port.yang sonic-show-techsupport.yang sonic-showtech-annot.yang openconfig-acl.yang openconfig-acl-annot.yang]
Found version 1.0.2 for yang module openconfig-aclI0501 14:10:35.638331    1337 app_interface.go:99] Registering for path =/openconfig-acl:acl
I0501 14:10:35.638370    1337 app_interface.go:99] Registering for path =/sonic-
I0501 14:10:35.638392    1337 app_interface.go:99] Registering for path =*
I0501 14:10:35.638420    1337 intf_app.go:93] Init called for INTF module
I0501 14:10:35.638438    1337 app_interface.go:99] Registering for path =/openconfig-interfaces:interfaces
I0501 14:10:35.638457    1337 lldp_app.go:61] Init called for LLDP modules module
I0501 14:10:35.638476    1337 app_interface.go:99] Registering for path =/openconfig-lldp:lldp
I0501 14:10:35.638499    1337 pfm_app.go:42] Init called for Platform module
I0501 14:10:35.638517    1337 app_interface.go:99] Registering for path =/openconfig-platform:components
I0501 14:10:35.809903    1337 sys_app.go:45] SysApp: Init called for System module
I0501 14:10:35.809968    1337 app_interface.go:99] Registering for path =/openconfig-system:system
I0501 14:10:35.810289    1337 version.go:144] *** Yang bundle version = 1.0.0
I0501 14:10:35.810333    1337 version.go:145] *** Yang base version   = 1.0.0
I0501 14:10:35.810360    1337 app_interface.go:99] Registering for path =/ietf-yang-library:modules-state
I0501 14:10:35.814109    1337 telemetry.go:51] client_auth not provided, using defaults.
E0501 14:10:35.814177    1337 telemetry.go:72] flag: log level 2
I0501 14:10:35.814263    1337 telemetry.go:95] Server Cert md5 checksum: f9dab5bcead206261f6370baf6244031 at time 2023-05-01 14:10:35.814236588 +0000 UTC
I0501 14:10:35.814307    1337 telemetry.go:96] Server Key md5 checksum: 63049431114bcab57791e12f50f371a4 at time 2023-05-01 14:10:35.814236588 +0000 UTC
F0501 14:10:35.814338    1337 telemetry.go:97] could not load server key pair: open /etc/sonic/telemetry/streamingtelemetryserver.cer: no such file or directory