Charlie Garrison
2010-Mar-05 08:55 UTC
[Nut-upsuser] Getting 'Data stale' error with bcmxcp_usb for a PowerWare 5115 on OSX
Good evening, I tried getting this to work a couple years back but didn't have enough time to do all the debugging that was needed (apologies to the devs who tried to help at that time). It's working much better now, but I'm still not able to get an answer from upsc. Can anyone help me work out why I'm getting the error when querying with upsc: Error: Data stale My environment: OSX 10.5.8 NUT 2.4.3 (also tried with latest svn) PowerWare 5115, USB version I'm able to compile/install without problems using (newly created user/group): $ ./configure --with-user=ups --with-group=nut --with-usb --with-drivers=bcmxcp_usb I added following to ups.conf: [powerware5115] driver = bcmxcp_usb port = auto desc = "Workstation" And I added LISTEN lines for both localhost and internal IP to upsd.conf. LISTEN 192.168.1.10 LISTEN 127.0.0.1 And the following to upsd.users: [nobody] password = <hidden> upsmon master And upsmon.conf: MONITOR powerware5115 at localhost 1 nobody <hidden> master The driver/daemons seem to run fine (except for error with upsmon): $ sudo /usr/local/ups/bin/upsdrvctl start Network UPS Tools - UPS driver controller 2.4.3-2392 Network UPS Tools - BCMXCP UPS driver 0.23 (2.4.3-2392) USB communication subdriver 0.18 $ sudo /usr/local/ups/sbin/upsd Network UPS Tools upsd 2.4.3-2392 listening on 127.0.0.1 port 3493 listening on 192.168.1.10 port 3493 Connected to UPS [powerware5115]: bcmxcp_usb-powerware5115 $ sudo /usr/local/ups/sbin/upsmon Network UPS Tools upsmon 2.4.3-2392 Using power down flag file /etc/killpower UPS: powerware5115 at localhost (master) (power value 1) Broadcast Message from charlie at workstation.garrison.com.au (no tty) at 19:49 EST... Communications with UPS powerware5115 at localhost lost Broadcast Message from charlie at workstation.garrison.com.au (no tty) at 19:49 EST... UPS powerware5115 at localhost is unavailable But I can't query the UPS: $ /usr/local/ups/bin/upsc powerware5115 Error: Data stale I can't see any errors from the driver in debug mode: $ sudo /usr/local/ups/bin/bcmxcp_usb -DD -a powerware5115 [debug output below] What can I do to troubleshoot this problem (assuming it should work to begin with)? Thanks, Charlie Network UPS Tools - BCMXCP UPS driver 0.23 (2.4.3-2392) USB communication subdriver 0.18 0.000000 debug level is '2' 0.329754 device 002-06da-0002-00-00 opened successfully 0.332582 entering get_answer(31) 1.083837 get_answer: (166 bytes) => ab 01 74 01 02 00 01 05 10 00 14 00 01 00 13 35 1.083919 31 31 35 31 30 30 30 41 20 20 20 20 20 20 20 20 20 20 51 00 00 00 00 00 00 1.084676 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 f0 00 f0 00 00 00 52 52 00 00 1.084704 00 00 52 f0 e2 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 1.084729 f0 00 00 f0 00 00 f0 00 00 41 00 00 41 00 00 f0 00 00 00 00 00 00 f0 00 00 1.084755 1b c0 01 00 8a ab 01 28 82 82 04 00 80 0b 00 00 00 00 00 00 00 40 00 00 00 1.084780 00 00 05 00 80 06 08 00 50 00 00 00 00 00 00 03 00 1b 18 00 00 00 11 00 2f 1.084794 get_answer: block_number = 1 1.084807 get_answer: sequence number (1) is ok 1.084821 get_answer: checksum is ok 1.084846 get_answer: block_number = 1 1.084861 get_answer: sequence number (2) is ok 1.084874 get_answer: checksum is ok 1.084888 get_answer: all data received 1.085396 Length of meter map: 81 1.085490 Index Offset Format NUT 1.085545 0021 0000 f0 None 1.085560 0023 0004 f0 ups.power 1.085601 0027 0008 52 output.frequency 1.085618 0028 0012 52 input.frequency 1.085632 0033 0016 52 battery.voltage 1.085673 0034 0020 f0 battery.charge 1.085688 0035 0024 e2 battery.runtime 1.085729 0056 0028 f0 input.voltage 1.085745 0059 0032 f0 None 1.085760 0062 0036 f0 ambient.temperature 1.085800 0065 0040 41 output.current 1.085815 0068 0044 41 output.current.nominal 1.085856 0071 0048 f0 None 1.085871 0078 0052 f0 output.voltage 1.085885 1.085925 Length of alarm map: 27 1.085939 Index Alarm Supported 1.085982 -001 INVERTER_AC_OVER_VOLTAGE No 1.085997 -001 INVERTER_AC_UNDER_VOLTAGE No 1.086011 -001 INVERTER_OVER_OR_UNDER_FREQ No 1.086053 -001 BYPASS_AC_OVER_VOLTAGE No 1.092701 -001 BYPASS_AC_UNDER_VOLTAGE No 1.092940 -001 BYPASS_OVER_OR_UNDER_FREQ No 1.092965 0000 INPUT_AC_OVER_VOLTAGE Yes 1.092980 0001 INPUT_AC_UNDER_VOLTAGE Yes 1.092994 0002 INPUT_UNDER_OR_OVER_FREQ Yes 1.099344 -001 OUTPUT_OVER_VOLTAGE No 1.099366 -001 OUTPUT_UNDER_VOLTAGE No 1.099380 -001 OUTPUT_UNDER_OR_OVER_FREQ No 1.099395 -001 REMOTE_EMERGENCY_PWR_OFF No 1.099409 -001 REMOTE_GO_TO_BYPASS No 1.099423 -001 BUILDING_ALARM_6 No 1.099437 -001 BUILDING_ALARM_5 No 1.099451 -001 BUILDING_ALARM_4 No 1.099465 -001 BUILDING_ALARM_3 No 1.099479 -001 BUILDING_ALARM_2 No 1.099493 -001 BUILDING_ALARM_1 No 1.099507 -001 STATIC_SWITCH_OVER_TEMP No 1.099522 -001 CHARGER_OVER_TEMP No 1.099536 -001 CHARGER_LOGIC_PWR_FAIL No 1.099550 -001 CHARGER_OVER_VOLTAGE_OR_CURRENT No 1.099564 -001 INVERTER_OVER_TEMP No 1.099884 0003 OUTPUT_OVERLOAD Yes 1.099900 -001 RECTIFIER_INPUT_OVER_CURRENT No 1.099914 -001 INVERTER_OUTPUT_OVER_CURRENT No 1.099928 -001 DC_LINK_OVER_VOLTAGE No 1.099943 -001 DC_LINK_UNDER_VOLTAGE No 1.099957 -001 RECTIFIER_FAILED No 1.099971 0004 INVERTER_FAULT Yes 1.099985 -001 BATTERY_CONNECTOR_FAIL No 1.099999 -001 BYPASS_BREAKER_FAIL No 1.100013 0005 CHARGER_FAIL Yes 1.100028 -001 RAMP_UP_FAILED No 1.100042 -001 STATIC_SWITCH_FAILED No 1.100056 -001 ANALOG_AD_REF_FAIL No 1.100070 -001 BYPASS_UNCALIBRATED No 1.100084 -001 RECTIFIER_UNCALIBRATED No 1.100098 -001 OUTPUT_UNCALIBRATED No 1.100112 -001 INVERTER_UNCALIBRATED No 1.100127 -001 DC_VOLT_UNCALIBRATED No 1.100141 -001 OUTPUT_CURRENT_UNCALIBRATED No 1.100155 -001 RECTIFIER_CURRENT_UNCALIBRATED No 1.100169 -001 BATTERY_CURRENT_UNCALIBRATED No 1.100183 -001 INVERTER_ON_OFF_STAT_FAIL No 1.100198 -001 BATTERY_CURRENT_LIMIT No 1.100212 -001 INVERTER_STARTUP_FAIL No 1.100725 -001 ANALOG_BOARD_AD_STAT_FAIL No 1.100744 -001 OUTPUT_CURRENT_OVER_100 No 1.100759 -001 BATTERY_GROUND_FAULT No 1.100773 -001 WAITING_FOR_CHARGER_SYNC No 1.100787 -001 NV_RAM_FAIL No 1.100802 -001 ANALOG_BOARD_AD_TIMEOUT No 1.100816 0006 SHUTDOWN_IMMINENT Yes 1.100830 0007 BATTERY_LOW Yes 1.100845 0008 UTILITY_FAIL Yes 1.100859 -001 OUTPUT_SHORT_CIRCUIT No 1.100874 0009 UTILITY_NOT_PRESENT Yes 1.100888 -001 FULL_TIME_CHARGING No 1.100902 -001 FAST_BYPASS_COMMAND No 1.100916 -001 AD_ERROR No 1.100930 -001 INTERNAL_COM_FAIL No 1.100944 -001 RECTIFIER_SELFTEST_FAIL No 1.100959 -001 RECTIFIER_EEPROM_FAIL No 1.100973 -001 RECTIFIER_EPROM_FAIL No 1.100987 -001 INPUT_LINE_VOLTAGE_LOSS No 1.101001 -001 BATTERY_DC_OVER_VOLTAGE No 1.101015 -001 POWER_SUPPLY_OVER_TEMP No 1.101029 -001 POWER_SUPPLY_FAIL No 1.101043 -001 POWER_SUPPLY_5V_FAIL No 1.101058 -001 POWER_SUPPLY_12V_FAIL No 1.101072 -001 HEATSINK_OVER_TEMP No 1.102622 -001 HEATSINK_TEMP_SENSOR_FAIL No 1.102651 -001 RECTIFIER_CURRENT_OVER_125 No 1.102665 -001 RECTIFIER_FAULT_INTERRUPT_FAIL No 1.102680 -001 RECTIFIER_POWER_CAPASITOR_FAIL No 1.102694 -001 INVERTER_PROGRAM_STACK_ERROR No 1.102708 -001 INVERTER_BOARD_SELFTEST_FAIL No 1.102722 -001 INVERTER_AD_SELFTEST_FAIL No 1.102737 -001 INVERTER_RAM_SELFTEST_FAIL No 1.102751 -001 NV_MEMORY_CHECKSUM_FAIL No 1.102765 -001 PROGRAM_CHECKSUM_FAIL No 1.102779 -001 INVERTER_CPU_SELFTEST_FAIL No 1.102793 -001 NETWORK_NOT_RESPONDING No 1.102807 -001 FRONT_PANEL_SELFTEST_FAIL No 1.102821 -001 NODE_EEPROM_VERIFICATION_ERROR No 1.102835 -001 OUTPUT_AC_OVER_VOLT_TEST_FAIL No 1.102849 -001 OUTPUT_DC_OVER_VOLTAGE No 1.102863 -001 INPUT_PHASE_ROTATION_ERROR No 1.102877 -001 INVERTER_RAMP_UP_TEST_FAILED No 1.102891 -001 INVERTER_OFF_COMMAND No 1.102905 -001 INVERTER_ON_COMMAND No 1.102919 -001 TO_BYPASS_COMMAND No 1.102933 -001 FROM_BYPASS_COMMAND No 1.103699 -001 AUTO_MODE_COMMAND No 1.103735 -001 EMERGENCY_SHUTDOWN_COMMAND No 1.103750 -001 SETUP_SWITCH_OPEN No 1.103960 -001 INVERTER_OVER_VOLT_INT No 1.103992 -001 INVERTER_UNDER_VOLT_INT No 1.104007 -001 ABSOLUTE_DCOV_ACOV No 1.104020 -001 PHASE_A_CURRENT_LIMIT No 1.104034 -001 PHASE_B_CURRENT_LIMIT No 1.104048 -001 PHASE_C_CURRENT_LIMIT No 1.104062 -001 BYPASS_NOT_AVAILABLE No 1.104076 -001 RECTIFIER_BREAKER_OPEN No 1.104090 -001 BATTERY_CONTACTOR_OPEN No 1.104104 -001 INVERTER_CONTACTOR_OPEN No 1.104119 -001 BYPASS_BREAKER_OPEN No 1.104133 -001 INV_BOARD_ACOV_INT_TEST_FAIL No 1.104147 -001 INVERTER_OVER_TEMP_TRIP No 1.104161 -001 INV_BOARD_ACUV_INT_TEST_FAIL No 1.104175 -001 INVERTER_VOLTAGE_FEEDBACK_ERROR No 1.104189 -001 DC_UNDER_VOLTAGE_TIMEOUT No 1.104203 -001 AC_UNDER_VOLTAGE_TIMEOUT No 1.104217 -001 DC_UNDER_VOLTAGE_WHILE_CHARGE No 1.104231 -001 INVERTER_VOLTAGE_BIAS_ERROR No 1.104245 -001 RECTIFIER_PHASE_ROTATION No 1.104259 -001 BYPASS_PHASER_ROTATION No 1.104273 -001 SYSTEM_INTERFACE_BOARD_FAIL No 1.104287 -001 PARALLEL_BOARD_FAIL No 1.105313 -001 LOST_LOAD_SHARING_PHASE_A No 1.105344 -001 LOST_LOAD_SHARING_PHASE_B No 1.105393 -001 LOST_LOAD_SHARING_PHASE_C No 1.105408 -001 DC_OVER_VOLTAGE_TIMEOUT No 1.105423 0010 BATTERY_TOTALLY_DISCHARGED Yes 1.105463 -001 INVERTER_PHASE_BIAS_ERROR No 1.105477 -001 INVERTER_VOLTAGE_BIAS_ERROR_2 No 1.105518 -001 DC_LINK_BLEED_COMPLETE No 1.105533 -001 LARGE_CHARGER_INPUT_CURRENT No 1.105547 -001 INV_VOLT_TOO_LOW_FOR_RAMP_LEVEL No 1.105589 -001 LOSS_OF_REDUNDANCY No 1.105603 -001 LOSS_OF_SYNC_BUS No 1.105646 -001 RECTIFIER_BREAKER_SHUNT_TRIP No 1.105661 -001 LOSS_OF_CHARGER_SYNC No 1.105675 -001 INVERTER_LOW_LEVEL_TEST_TIMEOUT No 1.105717 -001 OUTPUT_BREAKER_OPEN No 1.105731 -001 CONTROL_POWER_ON No 1.105772 -001 INVERTER_ON No 1.105787 -001 CHARGER_ON No 1.105801 -001 BYPASS_ON No 1.105843 -001 BYPASS_POWER_LOSS No 1.105857 -001 ON_MANUAL_BYPASS No 1.105899 -001 BYPASS_MANUAL_TURN_OFF No 1.105914 -001 INVERTER_BLEEDING_DC_LINK_VOLT No 1.105928 -001 CPU_ISR_ERROR No 1.105970 -001 SYSTEM_ISR_RESTART No 1.105984 -001 PARALLEL_DC No 1.106025 -001 BATTERY_NEEDS_SERVICE No 1.106040 -001 BATTERY_CHARGING No 1.106054 -001 BATTERY_NOT_CHARGED No 1.106096 -001 DISABLED_BATTERY_TIME No 1.106110 -001 SERIES_7000_ENABLE No 1.106152 -001 OTHER_UPS_ON No 1.106166 -001 PARALLEL_INVERTER No 1.106180 -001 UPS_IN_PARALLEL No 1.106222 -001 OUTPUT_BREAKER_REALY_FAIL No 1.106237 -001 CONTROL_POWER_OFF No 1.106277 -001 LEVEL_2_OVERLOAD_PHASE_A No 1.106292 -001 LEVEL_2_OVERLOAD_PHASE_B No 1.106306 -001 LEVEL_2_OVERLOAD_PHASE_C No 1.106443 -001 LEVEL_3_OVERLOAD_PHASE_A No 1.106457 -001 LEVEL_3_OVERLOAD_PHASE_B No 1.106472 -001 LEVEL_3_OVERLOAD_PHASE_C No 1.106486 -001 LEVEL_4_OVERLOAD_PHASE_A No 1.106500 -001 LEVEL_4_OVERLOAD_PHASE_B No 1.106514 -001 LEVEL_4_OVERLOAD_PHASE_C No 1.106561 0011 UPS_ON_BATTERY Yes 1.106575 -001 UPS_ON_BYPASS No 1.106590 0012 LOAD_DUMPED Yes 1.106629 -001 LOAD_ON_INVERTER No 1.106644 -001 UPS_ON_COMMAND No 1.106685 -001 UPS_OFF_COMMAND No 1.106699 -001 LOW_BATTERY_SHUTDOWN No 1.106713 -001 AUTO_ON_ENABLED No 1.106756 -001 SOFTWARE_INCOMPABILITY_DETECTED No 1.106770 -001 INVERTER_TEMP_SENSOR_FAILED No 1.106811 -001 DC_START_OCCURED No 1.106825 -001 IN_PARALLEL_OPERATION No 1.106840 -001 SYNCING_TO_BYPASS No 1.106881 -001 RAMPING_UPS_UP No 1.106896 -001 INVERTER_ON_DELAY No 1.106910 -001 CHARGER_ON_DELAY No 1.106924 -001 WAITING_FOR_UTIL_INPUT No 1.107084 -001 CLOSE_BYPASS_BREAKER No 1.107190 -001 TEMPORARY_BYPASS_OPERATION No 1.107210 -001 SYNCING_TO_OUTPUT No 1.107224 -001 BYPASS_FAILURE No 1.107239 -001 AUTO_OFF_COMMAND_EXECUTED No 1.107253 -001 AUTO_ON_COMMAND_EXECUTED No 1.107266 0013 BATTERY_TEST_FAILED Yes 1.107281 -001 FUSE_FAIL No 1.107295 0014 FAN_FAIL Yes 1.107309 0015 SITE_WIRING_FAULT Yes 1.107323 -001 BACKFEED_CONTACTOR_FAIL No 1.107337 -001 ON_BUCK No 1.107351 -001 ON_BOOST No 1.107365 -001 ON_DOUBLE_BOOST No 1.107379 -001 BATTERIES_DISCONNECTED No 1.107393 -001 UPS_CABINET_OVER_TEMP No 1.107407 -001 TRANSFORMER_OVER_TEMP No 1.107421 -001 AMBIENT_UNDER_TEMP No 1.107435 0016 AMBIENT_OVER_TEMP Yes 1.107449 -001 CABINET_DOOR_OPEN No 1.107463 -001 CABINET_DOOR_OPEN_VOLT_PRESENT No 1.107477 -001 AUTO_SHUTDOWN_PENDING No 1.107491 -001 TAP_SWITCHING_REALY_PENDING No 1.107505 -001 UNABLE_TO_CHARGE_BATTERIES No 1.107520 -001 STARTUP_FAILURE_CHECK_EPO No 1.107534 -001 AUTOMATIC_STARTUP_PENDING No 1.110475 -001 MODEM_FAILED No 1.110496 -001 INCOMING_MODEM_CALL_STARTED No 1.110542 -001 OUTGOING_MODEM_CALL_STARTED No 1.110557 -001 MODEM_CONNECTION_ESTABLISHED No 1.110597 -001 MODEM_CALL_COMPLETED_SUCCESS No 1.110611 1.110625 Length of Config_block: 80 1.110667 Length of statistics map: 0 1.110681 Length of command list: 24 1.110723 Length of outlet_block: 0 1.110738 Length of alarm_block: 17 1.112595 entering get_answer(36) 1.531682 get_answer: (85 bytes) => ab 06 50 81 23 01 ce c7 00 11 f4 01 f0 00 32 00 1.532055 00 00 00 33 ba 00 00 00 00 00 c9 0a a0 00 01 00 00 00 04 08 00 00 00 00 00 1.532081 01 05 10 00 00 00 00 00 00 00 1f 35 31 31 35 31 30 30 30 41 20 20 20 20 20 1.532104 20 20 55 58 32 30 35 41 30 35 37 37 20 20 20 20 20 20 35 1.532118 get_answer: block_number = 6 1.532132 get_answer: sequence number (1) is ok 1.532146 get_answer: checksum is ok 1.532160 get_answer: all data received 1.535766 entering get_answer(3c) 1.755718 get_answer: (36 bytes) => ab 0c 1f 81 f0 00 32 00 0d 00 43 30 f4 01 d8 00 1.755779 fe 00 00 00 02 01 ca 00 16 01 00 00 00 00 4b 01 00 00 00 0c 1.755841 get_answer: block_number = c 1.755859 get_answer: sequence number (1) is ok 1.755873 get_answer: checksum is ok 1.755886 get_answer: all data received 1.755935 entering init_command_map() 1.757669 entering get_answer(40) 1.949353 get_answer: (29 bytes) => ab 10 18 81 16 01 31 33 34 35 36 3b 3c 3f 40 42 1.949595 43 89 8a 8b 91 93 95 98 a0 b1 b2 cf 56 1.949618 get_answer: block_number = 10 1.949632 get_answer: sequence number (1) is ok 1.949789 get_answer: checksum is ok 1.949804 get_answer: all data received 1.949819 Command list block supported. 1.951681 entering get_answer(34) 2.283710 get_answer: (61 bytes) => ab 04 38 81 1c 01 00 00 38 01 00 00 00 00 48 42 2.283778 00 00 48 42 00 50 dc 41 64 00 00 00 06 04 00 00 fb 00 00 00 00 00 00 00 23 2.283874 00 00 00 00 80 95 3f ad 47 91 40 e8 03 00 00 fb 00 00 00 36 2.283888 get_answer: block_number = 4 2.283902 get_answer: sequence number (1) is ok 2.283916 get_answer: checksum is ok 2.284514 get_answer: all data received 2.285653 entering get_answer(35) 2.443724 get_answer: (22 bytes) => ab 05 11 81 00 00 00 00 00 00 00 00 00 00 00 00 2.444391 00 00 00 00 00 be 2.444640 get_answer: block_number = 5 2.444655 get_answer: sequence number (1) is ok 2.444669 get_answer: checksum is ok 2.444683 get_answer: all data received 2.447647 entering get_answer(33) 2.635717 get_answer: (25 bytes) => ab 03 13 81 50 c2 00 00 05 00 00 00 00 00 00 00 2.635774 00 00 00 00 00 00 00 a7 00 2.636578 get_answer: block_number = 3 2.636596 get_answer: sequence number (1) is ok 2.636610 get_answer: checksum is ok 2.636720 get_answer: all data received 2.639451 dstate_init: sock /var/state/ups/bcmxcp_usb-powerware5115 open on fd 4 2.645158 entering get_answer(34) 2.971759 get_answer: (61 bytes) => ab 04 38 81 1c 01 00 00 38 01 00 00 00 00 48 42 2.971826 00 00 48 42 00 50 dc 41 64 00 00 00 06 04 00 00 fb 00 00 00 00 00 00 00 23 2.972644 00 00 00 00 80 ac 3f ad 47 91 40 e8 03 00 00 fb 00 00 00 1f 2.972663 get_answer: block_number = 4 2.972943 get_answer: sequence number (1) is ok 2.972973 get_answer: checksum is ok 2.972987 get_answer: all data received 2.974736 entering get_answer(35) 3.131691 get_answer: (22 bytes) => ab 05 11 81 00 00 00 00 00 00 00 00 00 00 00 00 3.132186 00 00 00 00 00 be 3.132211 get_answer: block_number = 5 3.132227 get_answer: sequence number (1) is ok 3.132241 get_answer: checksum is ok 3.132255 get_answer: all data received 3.134670 entering get_answer(33) 3.324051 get_answer: (25 bytes) => ab 03 13 81 50 c2 00 00 05 00 00 00 00 00 00 00 3.324112 00 00 00 00 00 00 00 a7 00 3.329390 get_answer: block_number = 3 3.329413 get_answer: sequence number (1) is ok 3.329428 get_answer: checksum is ok 3.329442 get_answer: all data received 4.650156 entering get_answer(34) 5.006240 get_answer: (61 bytes) => ab 04 38 81 24 01 00 00 51 01 00 00 00 00 48 42 5.006315 00 00 48 42 00 50 dc 41 64 00 00 00 06 04 00 00 fb 00 00 00 00 00 00 00 23 5.006798 00 00 00 00 80 a3 3f ad 47 91 40 e8 03 00 00 fb 00 00 00 07 5.006820 get_answer: block_number = 4 5.006834 get_answer: sequence number (1) is ok 5.006848 get_answer: checksum is ok 5.006862 get_answer: all data received 5.010101 entering get_answer(35) 5.180594 get_answer: (22 bytes) => ab 05 11 81 00 00 00 00 00 00 00 00 00 00 00 00 5.180994 00 00 00 00 00 be 5.181010 get_answer: block_number = 5 5.181024 get_answer: sequence number (1) is ok 5.181038 get_answer: checksum is ok 5.181052 get_answer: all data received 5.183646 entering get_answer(33) 5.387731 get_answer: (25 bytes) => ab 03 13 81 50 c2 00 00 05 00 00 00 00 00 00 00 5.388134 00 00 00 00 00 00 00 a7 00 5.388149 get_answer: block_number = 3 5.388163 get_answer: sequence number (1) is ok 5.389918 get_answer: checksum is ok 5.390583 get_answer: all data received ^C 5.785337 Signal 2: exiting 5.794726 CLOSING -- ? Charlie Garrison ? <garrison at zeta.org.au> ? PO Box 141, Windsor, NSW 2756, Australia O< ascii ribbon campaign - stop html mail - www.asciiribbon.org http://www.ietf.org/rfc/rfc1855.txt
Arjen de Korte
2010-Mar-05 12:51 UTC
[Nut-upsuser] Getting 'Data stale' error with bcmxcp_usb for a PowerWare 5115 on OSX
Citeren Charlie Garrison <garrison at zeta.org.au>:> What can I do to troubleshoot this problem (assuming it should work > to begin with)?We need to know where the staleness warning is coming from first (driver, server or client). Run the server in debug mode for a while to see what it reports: /path/to/upsd -DDD Note the three D's here (not more, not less). Best regards, Arjen -- Please keep list traffic on the list
Charlie Garrison
2010-Mar-05 15:14 UTC
[Nut-upsuser] Getting 'Data stale' error with bcmxcp_usb for a PowerWare 5115 on OSX
Good morning, On 5/03/10 at 1:51 PM +0100, Arjen de Korte <nut+devel at de-korte.org> wrote:>Citeren Charlie Garrison <garrison at zeta.org.au>: > >>What can I do to troubleshoot this problem (assuming it should >>work to begin with)? > >We need to know where the staleness warning is coming from >first (driver, server or client). Run the server in debug mode >for a while to see what it reports: > >/path/to/upsd -DDD > >Note the three D's here (not more, not less).Thanks for the suggestion. Is the following useful information? $ sudo /usr/local/ups/sbin/upsd -DDD Network UPS Tools upsd 2.4.3-2392 0.000000 listen_add: added 192.168.1.10:3493 0.000526 listen_add: added 127.0.0.1:3493 0.001474 setuptcp: try to bind to 127.0.0.1 port 3493 0.002837 listening on 127.0.0.1 port 3493 0.003746 setuptcp: try to bind to 192.168.1.10 port 3493 0.004509 listening on 192.168.1.10 port 3493 0.055554 Connected to UPS [powerware5115]: bcmxcp_usb-powerware5115 0.117777 mainloop: polling 3 filedescriptors 0.131883 mainloop: polling 3 filedescriptors 0.142788 mainloop: polling 3 filedescriptors 0.145333 UPS [powerware5115]: dump is done 0.148405 sstate_dead: driver for UPS [powerware5115] says data is stale 0.149891 Data for UPS [powerware5115] is stale - check driver 0.152276 mainloop: polling 3 filedescriptors 2.153611 mainloop: no data available 2.154148 sstate_dead: driver for UPS [powerware5115] says data is stale 2.154699 mainloop: polling 3 filedescriptors ..... ^C 26.002941 mainloop: Interrupted system call 26.004085 Signal 2: exiting And I've found more info while testing which hopefully is a clue. If I start the driver with either of these commands: $ sudo /usr/local/ups/bin/upsdrvctl start $ sudo /usr/local/ups/bin/bcmxcp_usb -a powerware5115 Then I get the 'data stale' error. But if I start the driver with: $ sudo /usr/local/ups/bin/bcmxcp_usb -D -a powerware5115 Then I can run upsc and get an answer. So it works when running with driver in debug mode. Thanks, Charlie -- ? Charlie Garrison ? <garrison at zeta.org.au> ? PO Box 141, Windsor, NSW 2756, Australia O< ascii ribbon campaign - stop html mail - www.asciiribbon.org http://www.ietf.org/rfc/rfc1855.txt
Charlie Garrison
2010-Mar-06 06:26 UTC
[Nut-upsuser] Getting 'Data stale' error with bcmxcp_usb for a PowerWare 5115 on OSX
Good afternoon, On 5/03/10 at 8:35 PM +0100, Arjen de Korte <nut+users at de-korte.org> wrote:>>Then I can run upsc and get an answer. So it works when >>running with driver in debug mode. > >As the debug output from the server already suggested, the >problem seems to be in the driver. The difference between >running in normal and debug mode is that it won't background >and won't write a PID file in debug mode. This is unexpected. >Since backgrounding doesn't seem to be a problem, could you >check if the PID file is there? And the config.log would be >helpful, to see what is available on your system.Yes, the PID is there: $ sudo ls -l /var/state/ups/ total 16 srw-rw---- 1 _ups _nut 0 6 Mar 11:40 bcmxcp_usb-powerware5115 -rw-r--r-- 1 _ups _nut 6 6 Mar 11:40 bcmxcp_usb-powerware5115.pid -rw-r--r-- 1 _ups _nut 6 6 Mar 02:03 upsd.pid $ sudo less /var/state/ups/bcmxcp_usb-powerware5115.pid 59729 I tried inlining the config.log but message was rejected due to size. It's attached as gzip instead. Thanks, Charlie -- ? Charlie Garrison ? <garrison at zeta.org.au> ? PO Box 141, Windsor, NSW 2756, Australia O< ascii ribbon campaign - stop html mail - www.asciiribbon.org http://www.ietf.org/rfc/rfc1855.txt -------------- next part -------------- A non-text attachment was scrubbed... Name: config.log.gz Type: application/octet-stream Size: 13117 bytes Desc: not available URL: <http://lists.alioth.debian.org/pipermail/nut-upsuser/attachments/20100306/2ff5223c/attachment-0001.obj>
Charlie Garrison
2010-Mar-13 13:03 UTC
[Nut-upsdev] Getting 'Data stale' error with bcmxcp_usb for a PowerWare 5115 on OSX
Good evening, On 10/03/10 at 7:54 AM -0500, Charles Lepple <clepple at gmail.com> wrote:>On Wed, Mar 10, 2010 at 4:08 AM, Charlie Garrison <garrison at zeta.org.au> wrote: >>Good evening, >> >>On 8/03/10 at 11:54 PM -0500, Charles Lepple <clepple at gmail.com> wrote: >> >>>If you have time to add some upslogx() calls to the driver, I would be >>>interested in comparing the errors you are experiencing when not running in >>>debug mode. When the tripplite_usb driver is in the background, it logs the >>>following: >>> >>>3/8/10 11:26:04 PM tripplite_usb[22267] Error reading S value: Device >>>detached? (error 0: libusb/darwin.c usb_setup_iterator: >>>IOServiceGetMatchingServices: unknown error >>>) >> >>I'm not seeing anything like that. > >The second part of the error comes from usb_strerror(), so can you >change line 155 in your modified version to: > >upslogx(LOG_WARNING, "usb_interrupt_read is %d (%s)", res, usb_strerror());I changed that line, and output in terminal showed 'no error', eg: usb_interrupt_read is 25 (No error) And console log (after process forks) showed errors such as: bcmxcp_usb[71254] usb_interrupt_read is -6 (usb_bulk_read: An error occured during read (see messages above)) I couldn't see any 'messages above'; I'm not sure what that refers to. So I asked google about that error and during my reading, I got a clue about libusb versions. I'm using the mac ports system and it was (or I was) confused about which version of libusb was being used. It was on old version (0.1.12, even though 1.0.6 was installed). Anyway, after removing the 0.1.12 version I'm now getting `configure` errors with libusb-1.0.6. In particular: configure: error: "USB drivers requested, but libusb not found." I was getting other errors which were solved by adding symlinks for different versions/names; eg: $ ln -s libusb-1.0.pc /opt/local/lib/pkgconfig/libusb.pc $ ln -s libusb.h /opt/local/include/libusb-1.0/usb.h $ ln -s libusb-1.0.0.dylib /opt/local/lib/libusb.dylib $ ln -s libusb-1.0.a /opt/local/lib/libusb.a $ ln -s libusb-1.0.la /opt/local/lib/libusb.la That silenced all the other errors, but I'm still getting the "libusb not found" error. For reference, configure prints: checking for libusb version via pkg-config... 1.0.6 found checking for libusb cflags... -I/opt/local/include/libusb-1.0 checking for libusb ldflags... -L/opt/local/lib -lusb-1.0 checking for usb.h... yes checking for usb_init... no Should I be able to use libusb-1.0.6? I asked google about this configure error too but couldn't find anything useful. OK, I'm getting in a bit over my head, but after staring at code for libusb-1.0 it looks like the API has changed, and that would explain why `usb_init` check fails. I'll revert to 0.1.12; please advise if I should persist with upgrading to 1.0.6. And is there anything else I can test to help resolve this issue? Thanks again, Charlie -- ? Charlie Garrison ? <garrison at zeta.org.au> ? PO Box 141, Windsor, NSW 2756, Australia O< ascii ribbon campaign - stop html mail - www.asciiribbon.org http://www.ietf.org/rfc/rfc1855.txt
Charlie Garrison
2010-Mar-22 12:53 UTC
[Nut-upsdev] Getting 'Data stale' error with bcmxcp_usb for a PowerWare 5115 on OSX
Good evening, On 22/03/10 at 7:55 AM -0400, Charles Lepple <clepple at gmail.com> wrote:>On Mon, Mar 22, 2010 at 7:12 AM, Charlie Garrison <garrison at zeta.org.au> wrote: > >For the portion of the log quoted above, I admit I am not familiar >enough with this driver to say whether it has failed at this point. >Maybe someone from Eaton can comment on that.Is that a hint that I should be contacting them, or do we know they have devs on this list?>>454959.198654 ? Warning: excessive comm failures, limiting error reporting >>454959.198672 ? Communications with UPS lost: Error executing command > >The preceding two lines are generated from nutusb_comm_fail() in >bcmxcp_usb.c. What do you get from 'grep "Communications with UPS >lost" name-of-logfile' ?$ grep "Communications with UPS lost" /var/log/nut-driver.log 10578.415713 Communications with UPS lost: get_answer: checksum error! 11180.245313 Communications with UPS lost: get_answer: checksum error! 38876.625676 Communications with UPS lost: get_answer: checksum error! 46843.166524 Communications with UPS lost: get_answer: checksum error! 47954.281275 Communications with UPS lost: get_answer: checksum error! 52548.325592 Communications with UPS lost: get_answer: checksum error! 55334.000485 Communications with UPS lost: get_answer: checksum error! 69408.920215 Communications with UPS lost: get_answer: checksum error! 73109.467953 Communications with UPS lost: get_answer: checksum error! 81290.330831 Communications with UPS lost: get_answer: checksum error! 205872.380255 Communications with UPS lost: get_answer: checksum error! 281913.375308 Communications with UPS lost: get_answer: checksum error! 394369.162435 Communications with UPS lost: get_answer: checksum error! 454959.198672 Communications with UPS lost: Error executing command 454979.199631 Communications with UPS lost: Error executing command Note, the above possibly includes entries from the previous kill/restart, not just the last one. Although I'm pretty sure I rotated the log file last time, so that should be from one run of the driver.>>Does anyone have suggestions on how I can get the driver working on my >>system? IOW, any ideas on how it can recover without me having to >>dis/connect the USB cable and kill/restart the driver? > >So if I remember from your previous emails, killing and restarting the >driver without reconnecting the USB cable does /not/ solve the >problem?That is correct. And this time I was testing whether *only* dis/connecting the cable would allow the driver to recover. It did allow the loop processing to continue, but it didn't properly recover. I had to kill the driver daemon as well.>That sounds like an issue with the firmware on the UPS >itself. There is a function to reset the device that we could try, but >I think we may need to add some more debugging to figure out what >error codes should trigger this: > >http://libusb.sourceforge.net/doc/function.usbreset.htmlSorry, I'm missing the relevance here. Are you suggesting a one-time reset? Or should I add usb_reset somewhere in bcmxcp_usb.c? (My C skills aren't good enough to add that command and then open the device again.)>Did you have a debug statement around lines 150-160 in your code? I >would have thought we would see the error codes from >usb_interrupt_read().I did, but I removed them to reduce verbosity. I'll uncomment & recompile and run again.>We could probably set up a branch in SVN so that >we're working from the same piece of code. Have you built NUT from SVN >before? If not, no big deal - we can still work from snapshots.I've been working with r2392. I've just updated to r2405. I'm happy to work against a branch if you're able to create one and give me a commit bit. And thanks again, I appreciate the assistance. Charlie -- ? Charlie Garrison ? <garrison at zeta.org.au> ? PO Box 141, Windsor, NSW 2756, Australia O< ascii ribbon campaign - stop html mail - www.asciiribbon.org http://www.ietf.org/rfc/rfc1855.txt