Zenoss 4.2.5 Command Modeler plugin problems

7 posts / 0 new
Last post
Pheripheral
Pheripheral's picture
Offline
Last seen: 1 day 11 hours ago
Joined: 09/02/2015 - 04:52
Posts: 24
Zenoss 4.2.5 Command Modeler plugin problems

Hi,

My zenoss instance 'seems' to run fine, apart from when attempting to use Command modeler plugins, the modelling does not work.

Other modelling using snmp etc.. works ok, but if i use a command plugin i get a strange looping in the modeler output and it eventually times out.

Has any idea of what is going on and what could be causing it? 

 

The output from the modeler call on cmd line with -v10 logging level is:


[zenoss@box root]$ zenmodeler run -v10 -d 11.12.13.14 --collect zenoss.cmd.linux.cpuinfo
2017-03-17 16:12:36,237 DEBUG zen.ZenModeler: Run in foreground, starting immediately.
2017-03-17 16:12:36,237 DEBUG zen.ZenModeler: Starting PBDaemon initialization
2017-03-17 16:12:36,237 INFO zen.ZenModeler: Connecting to localhost:8789
2017-03-17 16:12:36,238 DEBUG zen.pbclientfactory: Starting connection...
2017-03-17 16:12:36,238 DEBUG zen.ZenModeler: Logging in as admin
2017-03-17 16:12:36,239 DEBUG zen.pbclientfactory: Connected
2017-03-17 16:12:36,239 DEBUG zen.pbclientfactory: Cancelling connect timeout
2017-03-17 16:12:36,239 DEBUG zen.pbclientfactory: Sending credentials
2017-03-17 16:12:36,265 DEBUG zen.pbclientfactory: Cancelling connect timeout
2017-03-17 16:12:36,265 INFO zen.ZenModeler: Connected to ZenHub
2017-03-17 16:12:36,265 DEBUG zen.ZenModeler: Setting up initial services: EventService, ModelerService
2017-03-17 16:12:36,265 DEBUG zen.ZenModeler: Chaining getInitialServices with d2
2017-03-17 16:12:36,265 DEBUG zen.pbclientfactory: pinging perspective
2017-03-17 16:12:36,266 DEBUG zen.ZenModeler: Loaded service EventService from zenhub
2017-03-17 16:12:36,266 DEBUG zen.ZenModeler: Loaded service ModelerService from zenhub
2017-03-17 16:12:36,267 DEBUG zen.ZenModeler: Queued event (total of 1) {'rcvtime': 1489767156.267047, 'severity': 0, 'component': 'zenmodeler', 'agent': 'zenmodeler', 'summary': 'started', 'manager': '<hostname>', 'device': 'localhost', 'eventClass': '/App/Start', 'monitor': 'localhost'}
2017-03-17 16:12:36,267 DEBUG zen.ZenModeler: Sending 1 events, 0 perf events, 0 heartbeats
2017-03-17 16:12:36,267 DEBUG zen.ZenModeler: Calling connected.
2017-03-17 16:12:36,267 DEBUG zen.ZenModeler: fetching monitor properties
2017-03-17 16:12:36,267 DEBUG zen.pbclientfactory: perspective ponged
2017-03-17 16:12:36,267 DEBUG zen.pbclientfactory: Cancelling ping timeout
2017-03-17 16:12:36,273 DEBUG zen.ZenModeler: Getting threshold classes...
2017-03-17 16:12:36,316 DEBUG zen.ZenModeler: Loading classes ['Products.ZenModel.MinMaxThreshold', 'Products.ZenModel.ValueChangeThreshold']
2017-03-17 16:12:36,317 DEBUG zen.ZenModeler: Fetching default RRDCreateCommand...
2017-03-17 16:12:36,335 DEBUG zen.ZenModeler: Getting collector thresholds...
2017-03-17 16:12:36,388 DEBUG zen.thresholds: Updating threshold ('high event queue', ('localhost collector', ''))
2017-03-17 16:12:36,388 DEBUG zen.thresholds: Updating threshold ('zenmodeler cycle time', ('localhost collector', ''))
2017-03-17 16:12:36,388 DEBUG zen.ZenModeler: Getting collector plugins for each DeviceClass
2017-03-17 16:12:36,431 DEBUG zen.ZenModeler: Starting collector loop...
2017-03-17 16:12:36,432 INFO zen.ZenModeler: Collecting for device 11.12.13.14
2017-03-17 16:12:36,510 INFO zen.ZenModeler: skipping WMI-based collection, PySamba zenpack not installed
2017-03-17 16:12:36,576 DEBUG zen.ZenModeler: Loaded plugin zenoss.cmd.linux.cpuinfo
2017-03-17 16:12:36,576 INFO zen.ZenModeler: No Python plugins found for 11.12.13.14
2017-03-17 16:12:36,576 DEBUG zen.ZenModeler: Loaded plugin zenoss.cmd.linux.cpuinfo
2017-03-17 16:12:36,576 DEBUG zen.ZenModeler: Using zenoss.cmd.linux.cpuinfo on 11.12.13.14 because of --collect flag
2017-03-17 16:12:36,576 INFO zen.ZenModeler: Using SSH collection method for device 11.12.13.14
2017-03-17 16:12:36,576 INFO zen.ZenModeler: plugins: zenoss.cmd.linux.cpuinfo
2017-03-17 16:12:36,577 DEBUG zen.SshClient: 11.12.13.14 SshClient connecting to 11.12.13.14:22 with timeout 10.0 seconds
2017-03-17 16:12:36,577 INFO zen.ZenModeler: SNMP monitoring off for 11.12.13.14
2017-03-17 16:12:36,577 DEBUG zen.ZenModeler: Loaded plugin zenoss.cmd.linux.cpuinfo
2017-03-17 16:12:36,577 INFO zen.ZenModeler: No portscan plugins found for 11.12.13.14
2017-03-17 16:12:36,577 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:12:36,578 DEBUG zen.ZenModeler: Collection slots filled
2017-03-17 16:12:36,578 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:12:37,579 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:12:38,580 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:12:39,581 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:12:40,582 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:12:41,582 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:12:42,583 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:12:43,584 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:12:44,585 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:12:45,586 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:12:46,586 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:12:47,587 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:12:48,588 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:12:49,589 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:12:50,590 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:12:51,590 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:12:52,592 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:12:53,593 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:12:54,594 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:12:55,595 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:12:56,595 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:12:57,596 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:12:58,597 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:12:59,598 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:00,599 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:01,599 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:02,600 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:03,601 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:04,602 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:05,603 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:06,266 DEBUG zen.pbclientfactory: pinging perspective
2017-03-17 16:13:06,266 DEBUG zen.pbclientfactory: perspective ponged
2017-03-17 16:13:06,266 DEBUG zen.pbclientfactory: Cancelling ping timeout
2017-03-17 16:13:06,603 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:07,604 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:08,605 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:09,606 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:10,607 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:11,607 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:12,608 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:13,610 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:14,611 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:15,612 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:16,612 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:17,613 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:18,614 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:19,615 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:20,616 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:21,616 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:22,618 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:23,619 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:24,620 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:25,621 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:26,621 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:27,622 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:28,623 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:29,624 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:30,625 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:31,625 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:32,626 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:33,627 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:34,628 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:35,629 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:36,266 DEBUG zen.pbclientfactory: pinging perspective
2017-03-17 16:13:36,266 DEBUG zen.pbclientfactory: perspective ponged
2017-03-17 16:13:36,267 DEBUG zen.pbclientfactory: Cancelling ping timeout
2017-03-17 16:13:36,629 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:37,630 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:38,631 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:39,632 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:40,633 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:41,633 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:42,634 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:43,635 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:44,636 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:45,637 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:46,637 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:47,638 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:48,639 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:49,640 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:50,641 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:51,641 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:52,642 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:53,643 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:54,644 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:55,645 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:56,645 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:57,646 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:58,647 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:13:59,648 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:00,649 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:01,649 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:02,650 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:03,651 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:04,652 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:05,653 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:06,266 DEBUG zen.pbclientfactory: pinging perspective
2017-03-17 16:14:06,517 DEBUG zen.pbclientfactory: perspective ponged
2017-03-17 16:14:06,517 DEBUG zen.pbclientfactory: Cancelling ping timeout
2017-03-17 16:14:06,653 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:07,654 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:08,655 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:09,656 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:10,657 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:11,657 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:12,658 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:13,659 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:14,660 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:15,661 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:16,662 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:17,663 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:18,664 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:19,665 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:20,666 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:21,666 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:22,667 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:23,668 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:24,669 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:25,670 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:26,671 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:27,672 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:28,673 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:29,674 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:30,675 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:31,675 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:32,676 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:33,677 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:34,678 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:35,680 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:36,266 DEBUG zen.pbclientfactory: pinging perspective
2017-03-17 16:14:36,267 DEBUG zen.pbclientfactory: perspective ponged
2017-03-17 16:14:36,267 DEBUG zen.pbclientfactory: Cancelling ping timeout
2017-03-17 16:14:36,680 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:37,681 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:38,682 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:39,683 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:40,684 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:41,684 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:42,685 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:43,686 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:44,687 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:45,688 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:46,689 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:47,690 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:48,691 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:49,692 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:50,693 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:51,693 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:52,694 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:53,695 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:54,696 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:55,697 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:56,697 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:57,698 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:58,699 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:14:59,700 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:15:00,701 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:15:01,701 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:15:02,702 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:15:03,703 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:15:04,704 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:15:05,705 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:15:06,266 DEBUG zen.pbclientfactory: pinging perspective
2017-03-17 16:15:06,267 DEBUG zen.pbclientfactory: perspective ponged
2017-03-17 16:15:06,267 DEBUG zen.pbclientfactory: Cancelling ping timeout
2017-03-17 16:15:06,706 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:15:07,707 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:15:08,708 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:15:09,709 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:15:10,710 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:15:11,710 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:15:12,712 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:15:13,713 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:15:14,714 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:15:15,715 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:15:16,715 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:15:17,716 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:15:18,717 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:15:19,718 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:15:20,719 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:15:21,719 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:15:22,720 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:15:23,721 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:15:24,722 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:15:25,723 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:15:26,724 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:15:27,725 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:15:28,726 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:15:29,727 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:15:30,728 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:15:31,728 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:15:32,729 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:15:33,730 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:15:34,731 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:15:35,732 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:15:36,266 DEBUG zen.pbclientfactory: pinging perspective
2017-03-17 16:15:36,267 DEBUG zen.pbclientfactory: perspective ponged
2017-03-17 16:15:36,267 DEBUG zen.pbclientfactory: Cancelling ping timeout
2017-03-17 16:15:36,732 WARNING zen.ZenModeler: Client 11.12.13.14 timeout
2017-03-17 16:15:36,732 DEBUG zen.ZenModeler: Running 0 clients
2017-03-17 16:15:36,732 INFO zen.ZenModeler: Scan time: 180.30 seconds
2017-03-17 16:15:36,742 DEBUG zen.thresholds: Checking value 180.300523043 on Daemons/localhost/zenmodeler_cycleTime
2017-03-17 16:15:36,796 DEBUG zen.MinMaxCheck: Checking zenmodeler_cycleTime 180.300523043 against min None and max 34560.0
2017-03-17 16:15:36,822 DEBUG zen.ZenModeler: Queued event (total of 1) {'zenoss.device.url': 'zport/dmd/Monitors/Performance/localhost/viewDaemonPerformance', 'zenoss.device.path': 'Monitors/Performance/localhost', 'severity': 0, 'min': None, 'max': 34560.0, 'component': '', 'agent': 'zenmodeler', 'summary': 'threshold of zenmodeler cycle time restored: current value 180.300523', 'current': 180.30052304267883, 'manager': '<hostname>', 'eventKey': 'zenmodeler cycle time', 'rcvtime': 1489767336.822832, 'device': 'localhost collector', 'eventClass': '/Perf', 'monitor': 'localhost'}
2017-03-17 16:15:36,823 DEBUG zen.collector.scheduler: In shutdown stage before
2017-03-17 16:15:36,823 DEBUG zen.ZenModeler: Tried to stop reactor that was stopped
2017-03-17 16:15:36,823 INFO zen.ZenModeler: Daemon ZenModeler shutting down
2017-03-17 16:15:36,823 DEBUG zen.ZenModeler: Sending 1 events, 0 perf events, 0 heartbeats
2017-03-17 16:15:36,840 DEBUG zen.ZenModeler: Removing service EventService
2017-03-17 16:15:36,840 DEBUG zen.ZenModeler: Removing service ModelerService
2017-03-17 16:15:36,840 DEBUG zen.pbclientfactory: Lost connection to ::1:8789 - [Failure instance: Traceback (failure with no frames): <class 'twisted.internet.error.ConnectionLost'>: Connection to the other side was lost in a non-clean fashion: Connection lost.
]
2017-03-17 16:15:36,840 DEBUG zen.collector.scheduler: In shutdown stage during
2017-03-17 16:15:36,840 DEBUG zen.collector.scheduler: In shutdown stage after

 

Any ideas gratefully received.

 

 

Jcurry
Jcurry's picture
Offline
Last seen: 1 day 11 hours ago
Joined: 01/02/2014 - 13:04
Posts: 391
Have you checked the ssh

Have you checked the ssh credentials that Zenoss has for 11.12.13.14 (the zCommand properties)?  Is that really a good address? Can you ssh to the box with those credentials from a command line?  Is port 22 open on the target?  Blocked somewhere in the network by a firewall?

Cheers,

Jane

Pheripheral
Pheripheral's picture
Offline
Last seen: 1 day 11 hours ago
Joined: 09/02/2015 - 04:52
Posts: 24
Hi,  

Hi,  

Thanks for replying.

Yep, I've checked the command properties for my device are correct and I can also ssh successfully from the zenoss server cmd line into my target box, thus (I think) proving that port 22 is open on the target.

I don't get any error message when i try to model it with the zcommand properties set purposefully incorrectly either, which suggests its not even getting as far as attempting to pass the credentials!

I've found that this problem is only occuring when attempting on a certain type of device and ssh command modelling works ok on other devices.  So it must be something about this specific set of devices on this particular kit setup, which are all Dell M1000e chassis's. Strangely, I can model via ssh command modeller on a device of this type on a different kit setup.

I'm unable to work out from the twisted code exactly where it has the problem that causes the looping in the sshclient / zenmodeler code...I would hope that if it was some port blocking or credential problem that an error message would be returned and the modelling attempt stopped rather than this looping that i see.

So i'm feeling a bit stuck as to for what to look for now? 

Does the zenoss attempt at ssh / command use anything slightly different in its connection attempts to what would be used for the manual ssh attempt (which works ok)?

(i've changed the ip address in my post to an example 11.12.13.14 from our actual ip)

 

Thanks

Jcurry
Jcurry's picture
Offline
Last seen: 1 day 11 hours ago
Joined: 01/02/2014 - 13:04
Posts: 391
Looking at the ZenPack, the

Looking at the ZenPack, the modeler runs "/bin/cat /proc/cpuinfo" - can you run that via ssh from a command line?

The command run by the monitoring template for cpu seems to be  "/bin/cat /proc/stat"  . Can you run this over shh from a command line terminal?  If so, try running zencommand against your specific device with the --showfull parameter and send the output to a file so:

zencommand run -v 10 -d 11.12.13.14 --showfullcommand > /tmp/fred 2>&1

/tmp/fred should then show you the exact command sent and the ssh dialogue.

Another thought - can your ping 11.12.13.14 from Zenoss?  The modeler and zencommand will check whether the device is "up" using ping, unless you have zPingMonitorIgnore set to True - if ping fails, it won't bother trying anything else.

Cheers,

Jane

Pheripheral
Pheripheral's picture
Offline
Last seen: 1 day 11 hours ago
Joined: 09/02/2015 - 04:52
Posts: 24
I can ssh to the target and

I can ssh to the target and run various commands ok. The particular cmd for cpuinfo is not actually present on my target, but if the command modeler was running ok it should show me an error message along these lines? 

I can ping the target ok aswell and its marked as Up in zenoss

I've setup a dummy command template to and applied them to the device and then run the zencommand with --showfullcommand as suggested and captured the output. This does attempt to connect via ssh and run my command but is nto successful.

 

2017-03-27 13:29:25,704 DEBUG zen.zencommand: Starting PBDaemon initialization
2017-03-27 13:29:25,704 INFO zen.zencommand: Connecting to localhost:8789
2017-03-27 13:29:25,705 DEBUG zen.pbclientfactory: Starting connection...
2017-03-27 13:29:25,705 DEBUG zen.zencommand: Logging in as admin
2017-03-27 13:29:25,706 DEBUG zen.pbclientfactory: Connected
2017-03-27 13:29:25,706 DEBUG zen.pbclientfactory: Cancelling connect timeout
2017-03-27 13:29:25,706 DEBUG zen.pbclientfactory: Sending credentials
2017-03-27 13:29:25,707 DEBUG zen.pbclientfactory: Cancelling connect timeout
2017-03-27 13:29:25,708 INFO zen.zencommand: Connected to ZenHub
2017-03-27 13:29:25,708 DEBUG zen.zencommand: Setting up initial services: EventService, Products.ZenHub.services.CommandPerformanceConfig
2017-03-27 13:29:25,708 DEBUG zen.zencommand: Chaining getInitialServices with d2
2017-03-27 13:29:25,708 DEBUG zen.pbclientfactory: pinging perspective
2017-03-27 13:29:25,709 DEBUG zen.zencommand: Loaded service EventService from zenhub
2017-03-27 13:29:25,709 DEBUG zen.zencommand: Loaded service Products.ZenHub.services.CommandPerformanceConfig from zenhub
2017-03-27 13:29:25,709 DEBUG zen.zencommand: Queued event (total of 1) {'rcvtime': 1490617765.709876, 'severity': 0, 'component': 'zencommand', 'agent': 'zencommand', 'summary': 'started', 'manager': '<hostname>', 'device': 'localhost', 'eventClass': '/App/Start', 'monitor': 'localhost'}
2017-03-27 13:29:25,710 DEBUG zen.zencommand: Sending 1 events, 0 perf events, 0 heartbeats
2017-03-27 13:29:25,710 DEBUG zen.zencommand: Calling connected.
2017-03-27 13:29:25,710 DEBUG zen.collector.config: Heartbeat timeout set to 900s
2017-03-27 13:29:25,710 DEBUG zen.collector.scheduler: add task configLoader, <Products.ZenCollector.config.ConfigurationLoaderTask object at 0x6d25690> using 1200 second interval
2017-03-27 13:29:25,710 DEBUG zen.zencommand: Performing periodic maintenance
2017-03-27 13:29:25,710 DEBUG zen.pbclientfactory: perspective ponged
2017-03-27 13:29:25,710 DEBUG zen.pbclientfactory: Cancelling ping timeout
2017-03-27 13:29:25,711 DEBUG zen.collector.scheduler: Task configLoader starting (waited 0 seconds) on 1200 second intervals
2017-03-27 13:29:25,711 DEBUG zen.collector.scheduler: Task configLoader changing state from IDLE to QUEUED
2017-03-27 13:29:25,711 DEBUG zen.collector.scheduler: Task configLoader changing state from QUEUED to RUNNING
2017-03-27 13:29:25,712 DEBUG zen.collector.config: configLoader gathering configuration
2017-03-27 13:29:25,712 DEBUG zen.collector.config: Fetching daemon configuration properties
2017-03-27 13:29:25,723 DEBUG zen.collector.scheduler: Task configLoader changing state from RUNNING to FETCHING_MISC_CONFIG
2017-03-27 13:29:25,723 DEBUG zen.zencommand: Updated configCycleInterval preference to 360
2017-03-27 13:29:25,723 DEBUG zen.zencommand: Changing config task interval from 20 to 360 minutes
2017-03-27 13:29:25,723 DEBUG zen.collector.scheduler: Stopping task configLoader, <Products.ZenCollector.config.ConfigurationLoaderTask object at 0x6d25690>
2017-03-27 13:29:25,723 DEBUG zen.collector.scheduler: call finished LoopingCall<1200>(CallableTask: configLoader, *(), **{}) : LoopingCall<1200>(CallableTask: configLoader, *(), **{})
2017-03-27 13:29:25,724 INFO zen.collector.scheduler: Detailed Task Statistics:
configLoader Current State: FETCHING_MISC_CONFIG Successful_Runs: 1 Failed_Runs: 0 Missed_Runs: 0

Detailed Task States:
configLoader State: RUNNING Total: 1 Total Elapsed: 0.0117 Min: 0.0117 Max: 0.0117 Mean: 0.0117 StdDev: 0.0000
configLoader State: QUEUED Total: 1 Total Elapsed: 0.0008 Min: 0.0008 Max: 0.0008 Mean: 0.0008 StdDev: 0.0000


2017-03-27 13:29:25,724 DEBUG zen.collector.config: Heartbeat timeout set to 900s
2017-03-27 13:29:25,724 DEBUG zen.collector.scheduler: add task configLoader, <Products.ZenCollector.config.ConfigurationLoaderTask object at 0x6f49e10> using 21600 second interval
2017-03-27 13:29:25,724 DEBUG zen.zencommand: Updated defaultRRDCreateCommand preference to ('RRA:AVERAGE:0.5:1:600', 'RRA:AVERAGE:0.5:6:600', 'RRA:AVERAGE:0.5:24:600', 'RRA:AVERAGE:0.5:288:600', 'RRA:MAX:0.5:6:600', 'RRA:MAX:0.5:24:600', 'RRA:MAX:0.5:288:600')
2017-03-27 13:29:25,724 DEBUG zen.collector.config: Fetching threshold classes
2017-03-27 13:29:25,730 DEBUG zen.zencommand: Loading classes ['Products.ZenModel.MinMaxThreshold', 'Products.ZenModel.ValueChangeThreshold']
2017-03-27 13:29:25,731 DEBUG zen.collector.config: Fetching collector thresholds
2017-03-27 13:29:25,765 DEBUG zen.thresholds: Updating threshold ('high event queue', ('localhost collector', ''))
2017-03-27 13:29:25,765 DEBUG zen.thresholds: Updating threshold ('zenmodeler cycle time', ('localhost collector', ''))
2017-03-27 13:29:25,765 DEBUG zen.collector.config: Fetching configurations
2017-03-27 13:29:25,797 DEBUG zen.zencommand: updateDeviceConfigs: updatedConfigs=['11.0.0.188']
2017-03-27 13:29:25,797 DEBUG zen.zencommand: Processing configuration for 11.0.0.188
2017-03-27 13:29:25,797 DEBUG zen.daemon: DummyListener: configuration 11.0.0.188 added
2017-03-27 13:29:25,797 DEBUG zen.collector.tasks: Splitting config 11.0.0.188
2017-03-27 13:29:25,797 DEBUG zen.zencommand: Tasks for config 11.0.0.188: {'11.0.0.188 300 Remote': <__main__.SshPerformanceCollectionTask object at 0x5edb110>}
2017-03-27 13:29:25,797 DEBUG zen.collector.scheduler: add task 11.0.0.188 300 Remote, COMMAND schedule Name: 11.0.0.188 300 Remote configId: 11.0.0.188 Datasources: 1 using 300 second interval
2017-03-27 13:29:25,798 DEBUG zen.collector.scheduler: Task 11.0.0.188 300 Remote starting (waited 0 seconds) on 300 second intervals
2017-03-27 13:29:25,798 DEBUG zen.collector.scheduler: Task 11.0.0.188 300 Remote changing state from IDLE to QUEUED
2017-03-27 13:29:25,798 DEBUG zen.zencommand: purgeOmittedDevices: deletedConfigs=
2017-03-27 13:29:25,798 DEBUG zen.collector.scheduler: Task configLoader finished, result: 'Configuration loaded'
2017-03-27 13:29:25,798 DEBUG zen.collector.scheduler: Task 11.0.0.188 300 Remote changing state from QUEUED to RUNNING
2017-03-27 13:29:25,798 DEBUG zen.collector.scheduler: Task 11.0.0.188 300 Remote changing state from RUNNING to CONNECTING
2017-03-27 13:29:25,798 DEBUG zen.zencommand: Creating connection object to 11.0.0.188
2017-03-27 13:29:25,798 INFO zen.zencommand: REACTOR type -> <twisted.internet.epollreactor.EPollReactor object at 0x351c7d0>
2017-03-27 13:29:25,798 DEBUG zen.SshClient: 11.0.0.188 SshClient connecting to 11.0.0.188:22 with timeout 10.0 seconds
2017-03-27 13:29:26,557 DEBUG zen.zencommand: Connection root:*****@11.0.0.188:22 lost.
2017-03-27 13:29:26,557 INFO zen.CmdClient: command client finished collection for 11.0.0.188
2017-03-27 13:29:26,557 DEBUG zen.zencommand: Deleting connection root:*****@11.0.0.188:22 from pool.
2017-03-27 13:29:26,557 DEBUG zen.collector.scheduler: Task 11.0.0.188 300 Remote changing state from CONNECTING to PAUSED
2017-03-27 13:29:26,557 ERROR zen.zencommand: Pausing task 11.0.0.188 300 Remote as 11.0.0.188 [11.0.0.188] connection failure: Connection was closed cleanly.
2017-03-27 13:29:26,557 DEBUG zen.zencommand: Queued event (total of 1) {'rcvtime': 1490617766.55763, 'monitor': 'localhost', 'component': 'zencommand', 'agent': 'zencommand', 'summary': 'Connection was closed cleanly.', 'manager': '<hostname>', 'device': '11.0.0.188', 'eventClass': '/Cmd/Fail', 'device_guid': '3739cb4b-358a-46d8-8b3d-af3fe71afd5f', 'severity': 4}
2017-03-27 13:29:26,557 DEBUG zen.zencommand: Collection time for 11.0.0.188 was 0.759147 seconds; cycle interval is 300 seconds.
2017-03-27 13:29:26,557 DEBUG zen.collector.scheduler: Task 11.0.0.188 300 Remote finished, result: <twisted.python.failure.Failure <class 'twisted.internet.error.ConnectionDone'>>
2017-03-27 13:29:26,557 DEBUG zen.collector.scheduler: Task 11.0.0.188 300 Remote changing state from PAUSED to IDLE
2017-03-27 13:29:26,557 INFO zen.zencommand: 1 devices processed (0 datapoints)
2017-03-27 13:29:26,558 INFO zen.collector.scheduler: Tasks: 2 Successful_Runs: 1 Failed_Runs: 0 Missed_Runs: 0 Queued_Tasks: 0 Running_Tasks: 1 
2017-03-27 13:29:26,558 DEBUG zen.collector.scheduler: Traceback (most recent call last):
Failure: twisted.internet.error.ConnectionDone: Connection was closed cleanly.

2017-03-27 13:29:26,558 DEBUG zen.collector.scheduler: COMMAND schedule Name: 11.0.0.188 300 Remote configId: 11.0.0.188 Datasources: 1 - 11.0.0.188 300 Remote failed [Failure instance: Traceback (failure with no frames): <class 'twisted.internet.error.ConnectionDone'>: Connection was closed cleanly.
]
2017-03-27 13:29:26,558 DEBUG zen.collector.scheduler: In shutdown stage before
2017-03-27 13:29:26,558 DEBUG zen.collector.scheduler: Stopping running task 11.0.0.188 300 Remote
2017-03-27 13:29:26,558 DEBUG zen.collector.scheduler: call finished LoopingCall<300>(CallableTask: 11.0.0.188 300 Remote, *(), **{}) : LoopingCall<300>(CallableTask: 11.0.0.188 300 Remote, *(), **{})
2017-03-27 13:29:26,558 DEBUG zen.collector.scheduler: Removing task 11.0.0.188 300 Remote
2017-03-27 13:29:26,558 DEBUG zen.collector.scheduler: Removing task configLoader
2017-03-27 13:29:26,558 DEBUG zen.collector.scheduler: tasks to clean KeyedSet([<Products.ZenCollector.config.ConfigurationLoaderTask object at 0x6d25690>, <Products.ZenCollector.config.ConfigurationLoaderTask object at 0x6f49e10>, <__main__.SshPerformanceCollectionTask object at 0x5edb110>])
2017-03-27 13:29:26,558 DEBUG zen.collector.scheduler: Cleanup on task configLoader <Products.ZenCollector.config.ConfigurationLoaderTask object at 0x6d25690>
2017-03-27 13:29:26,558 DEBUG zen.collector.scheduler: Scheduler._cleanupTaskComplete: result=None task.name=configLoader
2017-03-27 13:29:26,558 DEBUG zen.collector.scheduler: Cleanup on task configLoader <Products.ZenCollector.config.ConfigurationLoaderTask object at 0x6f49e10>
2017-03-27 13:29:26,558 DEBUG zen.collector.scheduler: Scheduler._cleanupTaskComplete: result=None task.name=configLoader
2017-03-27 13:29:26,558 DEBUG zen.collector.scheduler: Cleanup on task 11.0.0.188 300 Remote COMMAND schedule Name: 11.0.0.188 300 Remote configId: 11.0.0.188 Datasources: 1
2017-03-27 13:29:26,559 DEBUG zen.collector.scheduler: Scheduler._cleanupTaskComplete: result=None task.name=11.0.0.188 300 Remote
2017-03-27 13:29:26,559 DEBUG zen.zencommand: Tried to stop reactor that was stopped
2017-03-27 13:29:26,559 INFO zen.zencommand: Daemon CollectorDaemon shutting down
2017-03-27 13:29:26,559 DEBUG zen.zencommand: Sending 1 events, 0 perf events, 0 heartbeats
2017-03-27 13:29:26,566 DEBUG zen.zencommand: Removing service EventService
2017-03-27 13:29:26,566 DEBUG zen.zencommand: Removing service Products.ZenHub.services.CommandPerformanceConfig
2017-03-27 13:29:26,566 DEBUG zen.pbclientfactory: Lost connection to ::1:8789 - [Failure instance: Traceback (failure with no frames): <class 'twisted.internet.error.ConnectionLost'>: Connection to the other side was lost in a non-clean fashion: Connection lost.
]
2017-03-27 13:29:26,566 DEBUG zen.collector.scheduler: In shutdown stage during
2017-03-27 13:29:26,566 DEBUG zen.collector.scheduler: In shutdown stage after
Unhandled error in Deferred:
Unhandled Error
Traceback (most recent call last):
Failure: twisted.internet.error.ConnectionDone: Connection was closed cleanly.

This does attempt an ssh connection but almost immediately reports that the connection was lost:

2017-03-27 13:29:25,798 INFO zen.zencommand: REACTOR type -> <twisted.internet.epollreactor.EPollReactor object at 0x351c7d0>
2017-03-27 13:29:25,798 DEBUG zen.SshClient: 11.0.0.188 SshClient connecting to 11.0.0.188:22 with timeout 10.0 seconds
2017-03-27 13:29:26,557 DEBUG zen.zencommand: Connection root:*****@11.0.0.188:22 lost.

 

 

 

Pheripheral
Pheripheral's picture
Offline
Last seen: 1 day 11 hours ago
Joined: 09/02/2015 - 04:52
Posts: 24
I've compared the zenmodeler

I've compared the zenmodeler output from my troublesome devices versus the zenmodeler output from a device that connects ok and gives me error / success from the command and it seems to diverge at the point where the zenmodeler runs the collector client

2017-03-17 16:12:36,577 DEBUG zen.SshClient: 11.12.13.14 SshClient connecting to 11.12.13.14:22 with timeout 10.0 seconds
2017-03-17 16:12:36,577 INFO zen.ZenModeler: SNMP monitoring off for 11.12.13.14
2017-03-17 16:12:36,577 DEBUG zen.ZenModeler: Loaded plugin zenoss.cmd.linux.cpuinfo
2017-03-17 16:12:36,577 INFO zen.ZenModeler: No portscan plugins found for 11.12.13.14
2017-03-17 16:12:36,577 DEBUG zen.ZenModeler: Running 1 clients
2017-03-17 16:12:36,578 DEBUG zen.ZenModeler: Collection slots filled
2017-03-17 16:12:36,578 DEBUG zen.ZenModeler: Running 1 clients

A successful capture then starts to print info about host fingerprint and ssh connection and then runs the command, e.g.


2017-03-24 13:26:41,954 DEBUG zen.SshClient: 11.12.13.100 host fingerprint: 6f:79:1b:3b:f0:4b:7e:d1:95:76:39:24:8e:40:ad:1b
2017-03-24 13:26:41,961 DEBUG zen.SshClient: Creating new SSH connection...


 

whereas my problem devices don't even get as far as the fingerprint key part and just seem to loop the Running 1 clients message.

This makes me think that its never actually connecting to the ssh properly and so not actually even running the command. Very strange! because I can definitely connect to the problem targets with no issues via ssh from the zenoss server cmd line.

Pheripheral
Pheripheral's picture
Offline
Last seen: 1 day 11 hours ago
Joined: 09/02/2015 - 04:52
Posts: 24
Just done some more testing

Just done some more testing on the kit and narrowed 'something' down i think...

it seems its not a specific device type as such having a problem, but its a specific subnet of our ips having this looping / non ssh connection issue as any device on the troublesome subnet causes the same issue.

i.e. our devices are spread across ips such as

11.0.0.X
11.0.1.X
11.0.2.X

and only devices on 11.0.0.X have the ssh problem when running the modeler

these devices can all still be manually ssh'ed into from the zenoss cmd line though and zenoss knows that they are up so in terms of the network the zenoss box can see them, ping them and connect via manual ssh... non ssh modelling and collection also works ok...


do this new info lead to any new ideas of what could be the issue?

Log in to post comments