ObAgent 报错error="input plugin mysqlTableInput collect time out"

不好意思,之前用户名和密码弄错了。

$ grep -rn http_basic_auth_ obagent-only.yaml 
39:    http_basic_auth_user: admin
41:    http_basic_auth_password: root

附件是更改用户名和密码后得到的日志
goroutine.txt (132.2 KB)

没事的,你是obagent刚起来的时候请求的接口吗,我看里面的协程数量是三百多,问题不明显,可否进程起来两三分钟后请求下接口

上次抓的日志是obagent服务整个存活周期的日志。

这次等obagent起来120秒后开始收集日志,但是收集的日志为空。收集过程如下:

  1. 在执行’obd cluster restart obagent’后,当出现”Start obagent ok“时,开始采集日志
# date && sleep 120 && date  && curl -u admin:root http://localhost:8089/debug/pprof/goroutine?debug=1 --output /tmp/goroutine.txt
Wed Jul 26 14:37:21 CST 2023
Wed Jul 26 14:39:21 CST 2023
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
  0     0    0     0    0     0      0      0 --:--:--  0:01:38 --:--:--     0
curl: (52) Empty reply from server
  1. 在14:41:01左右时obagent自己死掉了
-bash-4.2$ date;sudo netstat -tnlp |grep 8089
Wed Jul 26 14:40:55 CST 2023
tcp6       0      0 :::8089                 :::*                    LISTEN      7459/monagent       
-bash-4.2$ date;sudo netstat -tnlp |grep 8089
Wed Jul 26 14:41:01 CST 2023

obagent的monagent.log日志最后50行

-bash-4.2$ tail -n 50 obagent/log/monagent.log 
2023-07-26T14:38:14.25003+08:00 INFO [7459,] caller=logrus/logrus_logger.go:33:Log:  fields: collector=loadavg, fields.level=debug, fields.msg="return load", index=0, load=51.86
2023-07-26T14:38:14.13034+08:00 WARN [7459,] caller=mysql/table_input.go:291:doCollect: condition not satisfied, skip do collect for:ob_index
2023-07-26T14:38:14.14489+08:00 INFO [7459,] caller=mysql/table_input.go:176:doUpdateCache: got update cache task for metric:ob_server_resource
2023-07-26T14:38:14.12156+08:00 INFO [7459,] caller=logrus/logrus_logger.go:33:Log:  fields: duration_seconds=24.355503041, fields.level=debug, fields.msg="collector succeeded", name=netstat
2023-07-26T14:38:14.18175+08:00 WARN [7459,] caller=mysql/table_input.go:202:collectData: slow collect sql: select /*+ MONITOR_AGENT READ_CONSISTENCY(WEAK) */ tenant_name, mem_used, access_count, hit_count from v$plan_cache_stat join __all_tenant on v$plan_cache_stat.tenant_id = __all_tenant.tenant_id group by tenant_name
2023-07-26T14:38:14.33016+08:00 WARN [7459,] caller=mysql/table_input.go:291:doCollect: condition not satisfied, skip do collect for:ob_index
2023-07-26T14:38:14.33401+08:00 WARN [7459,] caller=mysql/table_input.go:291:doCollect: condition not satisfied, skip do collect for:ob_index
2023-07-26T14:38:14.63514+08:00 WARN [7459,] caller=mysql/table_input.go:291:doCollect: condition not satisfied, skip do collect for:ob_role
2023-07-26T14:38:14.72703+08:00 WARN [7459,] caller=mysql/table_input.go:202:collectData: slow collect sql: select /*+ MONITOR_AGENT READ_CONSISTENCY(WEAK) */ zone, name, value, time_to_usec(now()) as current from __all_zone
2023-07-26T14:38:14.60916+08:00 WARN [7459,] caller=mysql/table_input.go:291:doCollect: condition not satisfied, skip do collect for:ob_table
2023-07-26T14:37:54.57107+08:00 INFO [7459,] caller=logrus/logrus_logger.go:33:Log:  fields: duration_seconds=28.961047601, fields.level=debug, fields.msg="collector succeeded", name=netdev
2023-07-26T14:38:14.74196+08:00 INFO [7459,] caller=logrus/logrus_logger.go:33:Log:  fields: collector=filesystem, fields.level=debug, fields.msg="Ignoring mount point", mountpoint=/sys
2023-07-26T14:38:07.36815+08:00 WARN [7459,] caller=mysql/table_input.go:291:doCollect: condition not satisfied, skip do collect for:ob_role
2023-07-26T14:38:14.66551+08:00 WARN [7459,] caller=mysql/table_input.go:291:doCollect: condition not satisfied, skip do collect for:ob_table
2023-07-26T14:37:54.5724+08:00 INFO [7459,] caller=logrus/logrus_logger.go:33:Log:  fields: collector=filesystem, fields.level=debug, fields.msg="Ignoring mount point", mountpoint=/proc
2023-07-26T14:38:07.44654+08:00 INFO [7459,] caller=logrus/logrus_logger.go:33:Log:  fields: duration_seconds=0.107484377, fields.level=debug, fields.msg="collector succeeded", name=sockstat
2023-07-26T14:38:15.11982+08:00 INFO [7459,] caller=logrus/logrus_logger.go:33:Log:  fields: duration_seconds=0.9601028, fields.level=debug, fields.msg="collector succeeded", name=filefd
2023-07-26T14:38:07.44724+08:00 WARN [7459,] caller=mysql/table_input.go:291:doCollect: condition not satisfied, skip do collect for:ob_role
2023-07-26T14:38:07.44783+08:00 WARN [7459,] caller=mysql/table_input.go:291:doCollect: condition not satisfied, skip do collect for:ob_index
2023-07-26T14:38:15.12428+08:00 INFO [7459,] caller=logrus/logrus_logger.go:33:Log:  fields: collector=meminfo, fields.level=debug, fields.msg="Set node_mem", memInfo="map[Active_anon_bytes:3.8125940736e+10 Active_bytes:4.0722161664e+10 Active_file_bytes:2.596220928e+09 AnonHugePages_bytes:3.5760635904e+10 AnonPages_bytes:3.8198648832e+10 Bounce_bytes:0 Buffers_bytes:0 Cached_bytes:4.974333952e+09 CmaFree_bytes:0 CmaTotal_bytes:0 CommitLimit_bytes:2.908071936e+10 Committed_AS_bytes:4.3259404288e+10 DirectMap2M_bytes:4.9725571072e+10 DirectMap4k_bytes:1.813905408e+09 Dirty_bytes:413696 HardwareCorrupted_bytes:0 HugePages_Free:0 HugePages_Rsvd:0 HugePages_Surp:0 HugePages_Total:0 Hugepagesize_bytes:2.097152e+06 Inactive_anon_bytes:9.8103296e+07 Inactive_bytes:2.44994048e+09 Inactive_file_bytes:2.351837184e+09 KernelStack_bytes:2.506752e+07 Mapped_bytes:1.57462528e+08 MemAvailable_bytes:4.711804928e+09 MemFree_bytes:5.453365248e+09 MemTotal_bytes:4.957151232e+10 Mlocked_bytes:0 NFS_Unstable_bytes:0 PageTables_bytes:1.00253696e+08 SReclaimable_bytes:2.14573056e+08 SUnreclaim_bytes:1.13364992e+08 Shmem_bytes:2.6267648e+07 Slab_bytes:3.27938048e+08 SwapCached_bytes:0 SwapFree_bytes:4.2949632e+09 SwapTotal_bytes:4.2949632e+09 Unevictable_bytes:0 VmallocChunk_bytes:3.515779487744e+13 VmallocTotal_bytes:3.5184372087808e+13 VmallocUsed_bytes:2.67952128e+08 WritebackTmp_bytes:0 Writeback_bytes:0]"
2023-07-26T14:38:07.44788+08:00 INFO [7459,] caller=logrus/logrus_logger.go:33:Log:  fields: collector=diskstats, device=sda7, fields.level=debug, fields.msg="Ignoring device"
2023-07-26T14:38:07.44932+08:00 ERROR [7459,] caller=engine/pipeline.go:154:collectAndProcess: input plugin collect failed fields: error="input plugin mysqlTableInput collect time out"
2023-07-26T14:37:49.36726+08:00 INFO [7459,] caller=logrus/logrus_logger.go:33:Log:  fields: collector=loadavg, fields.level=debug, fields.msg="return load", index=0, load=62.98
2023-07-26T14:37:49.37842+08:00 INFO [7459,] caller=logrus/logrus_logger.go:33:Log:  fields: duration_seconds=26.406036929, fields.level=debug, fields.msg="collector succeeded", name=netdev
2023-07-26T14:37:49.36975+08:00 ERROR [7459,] caller=engine/pipeline.go:154:collectAndProcess: input plugin collect failed fields: error="input plugin nodeExporterInput collect time out"
2023-07-26T14:38:15.12755+08:00 INFO [7459,] caller=logrus/logrus_logger.go:33:Log:  fields: collector=diskstats, device=sda2, fields.level=debug, fields.msg="Ignoring device"
2023-07-26T14:38:15.12784+08:00 INFO [7459,] caller=logrus/logrus_logger.go:33:Log:  fields: duration_seconds=0.457050261, fields.level=debug, fields.msg="collector succeeded", name=sockstat
2023-07-26T14:38:15.29322+08:00 INFO [7459,] caller=logrus/logrus_logger.go:33:Log:  fields: duration_seconds=0.550397693, fields.level=debug, fields.msg="collector succeeded", name=filefd
2023-07-26T14:38:15.33828+08:00 INFO [7459,] caller=logrus/logrus_logger.go:33:Log:  fields: collector=filesystem, fields.level=debug, fields.msg="Ignoring mount point", mountpoint=/sys
2023-07-26T14:38:15.27149+08:00 INFO [7459,] caller=logrus/logrus_logger.go:33:Log:  fields: duration_seconds=0.327219798, err="couldn't get SNTP reply: read udp 127.0.0.1:29564->127.0.0.1:123: read: connection refused", fields.level=error, fields.msg="collector failed", name=ntp
2023-07-26T14:38:15.15378+08:00 INFO [7459,] caller=logrus/logrus_logger.go:33:Log:  fields: collector=meminfo, fields.level=debug, fields.msg="Set node_mem", memInfo="map[Active_anon_bytes:3.813543936e+10 Active_bytes:4.0731635712e+10 Active_file_bytes:2.596196352e+09 AnonHugePages_bytes:3.5758538752e+10 AnonPages_bytes:3.8206726144e+10 Bounce_bytes:0 Buffers_bytes:0 Cached_bytes:4.974301184e+09 CmaFree_bytes:0 CmaTotal_bytes:0 CommitLimit_bytes:2.908071936e+10 Committed_AS_bytes:4.327460864e+10 DirectMap2M_bytes:4.9725571072e+10 DirectMap4k_bytes:1.813905408e+09 Dirty_bytes:380928 HardwareCorrupted_bytes:0 HugePages_Free:0 HugePages_Rsvd:0 HugePages_Surp:0 HugePages_Total:0 Hugepagesize_bytes:2.097152e+06 Inactive_anon_bytes:9.8103296e+07 Inactive_bytes:2.449936384e+09 Inactive_file_bytes:2.351833088e+09 KernelStack_bytes:2.5051136e+07 Mapped_bytes:1.57462528e+08 MemAvailable_bytes:4.7017984e+09 MemFree_bytes:5.443371008e+09 MemTotal_bytes:4.957151232e+10 Mlocked_bytes:0 NFS_Unstable_bytes:0 PageTables_bytes:1.00016128e+08 SReclaimable_bytes:2.14573056e+08 SUnreclaim_bytes:1.13340416e+08 Shmem_bytes:2.6267648e+07 Slab_bytes:3.27913472e+08 SwapCached_bytes:0 SwapFree_bytes:4.2949632e+09 SwapTotal_bytes:4.2949632e+09 Unevictable_bytes:0 VmallocChunk_bytes:3.515779487744e+13 VmallocTotal_bytes:3.5184372087808e+13 VmallocUsed_bytes:2.67952128e+08 WritebackTmp_bytes:0 Writeback_bytes:0]"
2023-07-26T14:38:15.33806+08:00 INFO [7459,] caller=logrus/logrus_logger.go:33:Log:  fields: duration_seconds=1.194037862, err="couldn't get SNTP reply: read udp 127.0.0.1:4853->127.0.0.1:123: read: connection refused", fields.level=error, fields.msg="collector failed", name=ntp
2023-07-26T14:38:15.49871+08:00 INFO [7459,] caller=logrus/logrus_logger.go:33:Log:  fields: collector=filesystem, fields.level=debug, fields.msg="Ignoring mount point", mountpoint=/sys
2023-07-26T14:38:15.45779+08:00 INFO [7459,] caller=logrus/logrus_logger.go:33:Log:  fields: duration_seconds=1.166190068, fields.level=debug, fields.msg="collector succeeded", name=sockstat
2023-07-26T14:38:15.29282+08:00 INFO [7459,] caller=logrus/logrus_logger.go:33:Log:  fields: duration_seconds=0.279434092, fields.level=debug, fields.msg="collector succeeded", name=filefd
2023-07-26T14:38:14.70768+08:00 INFO [7459,] caller=logrus/logrus_logger.go:33:Log:  fields: collector=diskstats, device=sda1, fields.level=debug, fields.msg="Ignoring device"
2023-07-26T14:40:49.5078+08:00 INFO [7459,] caller=logrus/logrus_logger.go:33:Log:  fields: duration_seconds=0.139579151, fields.level=debug, fields.msg="collector succeeded", name=filefd
2023-07-26T14:38:15.64761+08:00 INFO [7459,] caller=logrus/logrus_logger.go:33:Log:  fields: collector=loadavg, fields.level=debug, fields.msg="return load", index=0, load=51.79
2023-07-26T14:38:16.13725+08:00 INFO [7459,] caller=logrus/logrus_logger.go:33:Log:  fields: collector=diskstats, device=sda5, fields.level=debug, fields.msg="Ignoring device"
2023-07-26T14:38:16.29829+08:00 INFO [7459,] caller=logrus/logrus_logger.go:33:Log:  fields: duration_seconds=2.311804905, fields.level=debug, fields.msg="collector succeeded", name=sockstat
2023-07-26T14:38:16.12847+08:00 INFO [7459,] caller=logrus/logrus_logger.go:33:Log:  fields: collector=meminfo, fields.level=debug, fields.msg="Set node_mem", memInfo="map[Active_anon_bytes:3.8097973248e+10 Active_bytes:4.0694194176e+10 Active_file_bytes:2.596220928e+09 AnonHugePages_bytes:3.5760635904e+10 AnonPages_bytes:3.820032e+10 Bounce_bytes:0 Buffers_bytes:0 Cached_bytes:4.974333952e+09 CmaFree_bytes:0 CmaTotal_bytes:0 CommitLimit_bytes:2.908071936e+10 Committed_AS_bytes:4.3231092736e+10 DirectMap2M_bytes:4.9725571072e+10 DirectMap4k_bytes:1.813905408e+09 Dirty_bytes:413696 HardwareCorrupted_bytes:0 HugePages_Free:0 HugePages_Rsvd:0 HugePages_Surp:0 HugePages_Total:0 Hugepagesize_bytes:2.097152e+06 Inactive_anon_bytes:9.8103296e+07 Inactive_bytes:2.44994048e+09 Inactive_file_bytes:2.351837184e+09 KernelStack_bytes:2.506752e+07 Mapped_bytes:1.57462528e+08 MemAvailable_bytes:4.73872384e+09 MemFree_bytes:5.48028416e+09 MemTotal_bytes:4.957151232e+10 Mlocked_bytes:0 NFS_Unstable_bytes:0 PageTables_bytes:1.00253696e+08 SReclaimable_bytes:2.14573056e+08 SUnreclaim_bytes:1.13364992e+08 Shmem_bytes:2.6267648e+07 Slab_bytes:3.27938048e+08 SwapCached_bytes:0 SwapFree_bytes:4.2949632e+09 SwapTotal_bytes:4.2949632e+09 Unevictable_bytes:0 VmallocChunk_bytes:3.515779487744e+13 VmallocTotal_bytes:3.5184372087808e+13 VmallocUsed_bytes:2.67952128e+08 WritebackTmp_bytes:0 Writeback_bytes:0]"
2023-07-26T14:38:16.6346+08:00 ERROR [7459,] caller=engine/pipeline.go:154:collectAndProcess: input plugin collect failed fields: error="input plugin mysqlTableInput collect time out"
2023-07-26T14:38:16.76181+08:00 WARN [7459,] caller=mysql/table_input.go:205:collectData: failed to do collect with sql:select /*+ MONITOR_AGENT READ_CONSISTENCY(WEAK) */ tenant_name, mem_used, access_count, hit_count from V$OB_PLAN_CACHE_STAT join __all_tenant on V$OB_PLAN_CACHE_STAT.tenant_id = __all_tenant.tenant_id group by tenant_name[] Error 1146: Table 'oceanbase.V$OB_PLAN_CACHE_STAT' doesn't exist
2023-07-26T14:38:07.44793+08:00 WARN [7459,] caller=mysql/table_input.go:291:doCollect: condition not satisfied, skip do collect for:ob_table
2023-07-26T14:38:07.37615+08:00 ERROR [7459,] caller=engine/pipeline.go:154:collectAndProcess: input plugin collect failed fields: error="input plugin mysqlTableInput collect time out"
2023-07-26T14:37:49.38413+08:00 INFO [7459,] caller=logrus/logrus_logger.go:33:Log:  fields: collector=filesystem, fields.level=debug, fields.msg="Ignoring mount point", mountpoint=/proc
2023-07-26T14:37:49.38014+08:00 WARN [7459,] caller=mysql/table_input.go:291:doCollect: condition not satisfied, skip do collect for:ob_role
2023-07-26T14:38:07.35598+08:00 INFO [7459,] caller=logrus/logrus_logger.go:33:Log:  fields: collector=diskstats, device=sda2, fields.level=debug, fields.msg="Ignoring device"
2023-07-26T14:37:49.46473+08:00 WARN [7459,] caller=mysql/table_input.go:202:collectData: slow collect sql: select /*+ MONITOR_AGENT READ_CONSISTENCY(WEAK) */ tenant_name, tenant_id, stat_id, value from v$sysstat, __all_tenant where stat_id IN (10000, 10001, 10002, 10003, 10005, 10006, 140002, 140003, 140005, 140006, 60019, 60020, 60024, 80040, 80041, 130000, 130001, 130002, 130004, 20001, 20002, 30000, 30001, 30002, 30005, 30006, 40000, 40001, 40002, 40003, 40004, 40005, 40006, 40007, 40008, 40009, 40010, 40011, 40012, 50000, 50001, 50008, 50009, 60000, 60001, 60002, 60003, 60004, 60005, 60019, 60020, 60021, 60022, 60023, 60024, 80057) and (con_id > 1000 or con_id = 1) and __all_tenant.tenant_id = v$sysstat.con_id and class < 1000
2023-07-26T14:38:16.76669+08:00 WARN [7459,] caller=mysql/table_input.go:291:doCollect: condition not satisfied, skip do collect for:ob_table