CJVann Posted May 15, 2009 Posted May 15, 2009 These were in the log this last month. Do you think this is what caused the issue? What should I be doing differently? Internet access is not enabled on the ISY. 0 null Sat 04/18/2009 11:42:23 AM System -10011 0 null Sat 04/18/2009 05:46:24 PM System -10011 0 null Mon 04/20/2009 02:19:59 PM System -10011 0 null Sun 04/26/2009 10:06:53 AM System -10011 0 null Sun 04/26/2009 10:33:46 AM System -10011 0 null Sun 04/26/2009 11:00:03 AM System -10011 0 null Sun 04/26/2009 12:51:46 PM System -10011 0 null Tue 04/28/2009 10:25:25 AM System -10011 0 null Sun 05/03/2009 05:36:31 PM System -10011 0 null Fri 05/15/2009 04:46:25 PM System -10011
Michel Kohanim Posted May 18, 2009 Posted May 18, 2009 Hello CJVann, Thanks so very much for the logs and apologies for a tardy reply. No, I do not think so since the interval between each is too long. Bob, is there anything I can do to help debug this problem? With kind regards, Michel These were in the log this last month. Do you think this is what caused the issue? What should I be doing differently? Internet access is not enabled on the ISY. 0 null Sat 04/18/2009 11:42:23 AM System -10011 0 null Sat 04/18/2009 05:46:24 PM System -10011 0 null Mon 04/20/2009 02:19:59 PM System -10011 0 null Sun 04/26/2009 10:06:53 AM System -10011 0 null Sun 04/26/2009 10:33:46 AM System -10011 0 null Sun 04/26/2009 11:00:03 AM System -10011 0 null Sun 04/26/2009 12:51:46 PM System -10011 0 null Tue 04/28/2009 10:25:25 AM System -10011 0 null Sun 05/03/2009 05:36:31 PM System -10011 0 null Fri 05/15/2009 04:46:25 PM System -10011
bpwwer Posted May 18, 2009 Posted May 18, 2009 Michel, I just responded about these in the other thread about error messages. Is there any way to report what IP address (or better IP address / port) is the cause? I see these messages occasionally too and I'm pretty sure I don't have anything configured to attempt to connect the ISY with invalid userid/password. Just a though, but could these be reported if you attempt to connect with a browser and it tries without credentials first and then prompts for them? Hello CJVann, Bob, is there anything I can do to help debug this problem? With kind regards, Michel These were in the log this last month. Do you think this is what caused the issue? What should I be doing differently? Internet access is not enabled on the ISY. 0 null Sat 04/18/2009 11:42:23 AM System -10011 0 null Sat 04/18/2009 05:46:24 PM System -10011 0 null Mon 04/20/2009 02:19:59 PM System -10011 0 null Sun 04/26/2009 10:06:53 AM System -10011 0 null Sun 04/26/2009 10:33:46 AM System -10011 0 null Sun 04/26/2009 11:00:03 AM System -10011 0 null Sun 04/26/2009 12:51:46 PM System -10011 0 null Tue 04/28/2009 10:25:25 AM System -10011 0 null Sun 05/03/2009 05:36:31 PM System -10011 0 null Fri 05/15/2009 04:46:25 PM System -10011
Michel Kohanim Posted May 18, 2009 Posted May 18, 2009 Hi Bob, Yes, you are right: these can be generated if you use a browser and the first attempt is always without any credentials. As per my previous post, I was hunting down issues related to Network Magic which has a tendency of trying to login to all devices on the network every few seconds. Based on the posts above, I do not think HS Plugin is the cause for these problems. With kind regards, Michel Michel, I just responded about these in the other thread about error messages. Is there any way to report what IP address (or better IP address / port) is the cause? I see these messages occasionally too and I'm pretty sure I don't have anything configured to attempt to connect the ISY with invalid userid/password. Just a though, but could these be reported if you attempt to connect with a browser and it tries without credentials first and then prompts for them? Hello CJVann, Bob, is there anything I can do to help debug this problem? With kind regards, Michel These were in the log this last month. Do you think this is what caused the issue? What should I be doing differently? Internet access is not enabled on the ISY. 0 null Sat 04/18/2009 11:42:23 AM System -10011 0 null Sat 04/18/2009 05:46:24 PM System -10011 0 null Mon 04/20/2009 02:19:59 PM System -10011 0 null Sun 04/26/2009 10:06:53 AM System -10011 0 null Sun 04/26/2009 10:33:46 AM System -10011 0 null Sun 04/26/2009 11:00:03 AM System -10011 0 null Sun 04/26/2009 12:51:46 PM System -10011 0 null Tue 04/28/2009 10:25:25 AM System -10011 0 null Sun 05/03/2009 05:36:31 PM System -10011 0 null Fri 05/15/2009 04:46:25 PM System -10011
bpwwer Posted May 19, 2009 Posted May 19, 2009 CJVann, It's been a while since since up posted any updates on the HomeSeer forum, Have any of the newer versions of the plug-in helped? Based on this new information, it sounds like everything works ok for a while after rebooting the ISY and then it all stops -- you lose control from the plug-in and you can't log in to the ISY. If my summary's correct, for how long does it work before failing? Would it be possible to re-boot the ISY and pull the plug-in from HomeSeer or leave HomeSeer shutdown to see if happens without the plug-in? Socket Open Failed java.nio.channels.ClosedSelectorExceptionXML Parse Error http://x.x.x.x/desc Lately when I login to ISY (http://www.universal-devices.com/99i) the Admin Console opens but instead of the usual login pop-up, I get the above 2 errors in pop-up windows. I then have to reboot the ISY and I can then login. This occurs on each computer, and I've tried clearing Java. Is the ISY failing? Also, HomeSeer is unable to control the lights (thru the ISY) until the ISY is rebooted and HomeSeer is restarted. The only light lit on the ISY is Power. ISY V2.7.3
CJVann Posted May 21, 2009 Posted May 21, 2009 Hi Bob - So far, no further problems logging into the ISY. Here's some HS info that might help you spot something. I'm running HS 2.3.0.55 and ISY 2.7.3 with each of these plugin versions: 1.0.0.33: I get "COMM: ReadLine returned Null string - Is this fatal?" every 30 seconds. HS can control lights, but is unaware when you turn something on or off. I just returned home to find that HS said it couldn't find an ISY at it's last startup (it sometimes does that) so HS hasn't been doing anything with Insteon this week. It found the ISY okay when I restarted HS. 1.0.0.36 At each startup I get hundreds of errors per second saying "COMM: ReadLine returned Null string" followed by either "(0)" or "- ignore.", then HS crashes. 1.0.0.37 - Similar to 36 except errors only occur every 30 seconds and HS doesn't crash: 5/20/2009 10:33:37 PM ISY Insteon COMM: Readline returned Null string (0) 5/20/2009 10:33:37 PM ISY Insteon COMM: ReadLine returned Null string - connection dropped. I can control lights, but HS is unaware when you turn something on or off (can't trigger events). Let me know if you can think of anything else you'd like me to try.
bpwwer Posted May 21, 2009 Posted May 21, 2009 CJVann, I'd like to PM you and provide you with a URL where you can download a build with additional debugging messages if that's ok. I just though of something you could try. Try reseting your ISY username password back to the defaults and see if that works. Maybe the function that encodes the username/password string for the authorization header is not working right with some character your using. And I'm going to explain a bit about what the code is doing that leads up to this in case Michel has any ideas on what could be causing it. The error message below happens when trying to read to the TCP read on the socket set up for the subscription. I'm still using basic TCP functions to send the headers and set up the subscription. I do this in a thread and setup a subscription with REUSE_SOCKET and a duration of infinite. The connection succeeds. The writes to send the headers and SOAP request succeed. The readline() returns NULL. From what I can discover, readline() only returns NULL if the connection was dropped. I am trapping out of memory and timeout exceptions (which are the only exceptions it is suppose to throw). I can simulate this behavior by not sending the authorization header which leads me to the conclusion that maybe it's not authenticating properly and dropping the connection. However, the web services seem to be initializing properly and both are using the same variables for the username/password. Hi Bob - So far, no further problems logging into the ISY. Here's some HS info that might help you spot something. I'm running HS 2.3.0.55 and ISY 2.7.3 with each of these plugin versions: 1.0.0.33: I get "COMM: ReadLine returned Null string - Is this fatal?" every 30 seconds. HS can control lights, but is unaware when you turn something on or off. I just returned home to find that HS said it couldn't find an ISY at it's last startup (it sometimes does that) so HS hasn't been doing anything with Insteon this week. It found the ISY okay when I restarted HS. 1.0.0.36 At each startup I get hundreds of errors per second saying "COMM: ReadLine returned Null string" followed by either "(0)" or "- ignore.", then HS crashes. 1.0.0.37 - Similar to 36 except errors only occur every 30 seconds and HS doesn't crash: 5/20/2009 10:33:37 PM ISY Insteon COMM: Readline returned Null string (0) 5/20/2009 10:33:37 PM ISY Insteon COMM: ReadLine returned Null string - connection dropped. I can control lights, but HS is unaware when you turn something on or off (can't trigger events). Let me know if you can think of anything else you'd like me to try.
Michel Kohanim Posted May 21, 2009 Posted May 21, 2009 Hi Bob, The best thing to do is to look at the log and see if you are getting -1001x or -50xx the first case of which indicates authentication issue and the second indicates that the client didn't respond in a timely manner (there are too many packets in the backlog). With kind regards, Michel
CJVann Posted May 21, 2009 Posted May 21, 2009 FYI - I tried to open the ISY to capture the log this morning. Although it was working okay last night, I am now getting the following errors instead of a login prompt for user/password. (Also HS can no longer control any lighting): Socket Opened Failed java.net.SocketTimeoutException XML Parse Error http://x.x.x.x./descocket Open Failed java.nio.channels.ClosedSelectorException
CJVann Posted May 21, 2009 Posted May 21, 2009 Try reseting your ISY username password back to the defaults and see if that works. Maybe the function that encodes the username/password string for the authorization header is not working right with some character your using.Bob - I changed the user/pw both to "admin" and the errors stopped, and HS is now triggering events in response to Insteon button presses! I'll PM more details on HS's message board, but there were no unusal characters in my user or pw.
CJVann Posted May 21, 2009 Posted May 21, 2009 Hi Bob, The best thing to do is to look at the log and see if you are getting -1001x or -50xx the first case of which indicates authentication issue and the second indicates that the client didn't respond in a timely manner (there are too many packets in the backlog). With kind regards, Michel Here's some info that might help regarding the ISY login failure and -50's in the log. The only other -50's this month were on 5/15/09 (there were 3 of them within about 60 seconds). Here are the series of events prior to the failure: 5/20/09: I was able to login to the ISY okay this evening 5/20/09 10:33PM I restarted HomeSeer Kitchen: Light Status 0% Wed 05/20/2009 10:47:21 PM System Log 0 null Wed 05/20/2009 10:59:47 PM System -5012 0 null Wed 05/20/2009 11:00:18 PM System -5012 0 null Wed 05/20/2009 11:00:53 PM System -5012 5/21/09 6:30 AM: This is the first time I've tried to access the ISY since restarting HomeSeer last night, and the ISY will not let me in.
Michel Kohanim Posted May 21, 2009 Posted May 21, 2009 CJVann, If dropping subscriptions was the case, and based on what I know from HS plugin, I expected to see a lot more -5012s. As far as not being able to get to ISY, can you at least get to the HTML page? What error do you see? I think Bob is right: the authentication header for some reason is not being sent correctly and thus ISY is considering this a DOS. With kind regards, Michel
CJVann Posted May 21, 2009 Posted May 21, 2009 CJVann, If dropping subscriptions were the case, and based on what I know from HS plugin, I expected to see a lot more -5012s. The dropped subscriptions were caused by the the electric blinking off. The HomeSeer computer was on a UPS, so it wouldn't lose power. The ISY would reboot due to the power loss and sometimes got a new IP address that was different from what HomeSeer was using, so they would lose communications. I took the HomeSeer computer off of the UPS so they both reboot and synch IP addresses whenever the power blinks off (happens frequently here). As far as not being able to get to ISY, can you at least get to the HTML page? What error do you see? I login to ISY at this address: http://www.universal-devices.com/99i It displays the "Please Keep This Window Open!" screen, then loads the Admin Console window but instead of the pop-up window for Username and password, approx. every 15 seconds it pops up 3 little error message windows for these error messages: Socket Opened Failed java.net.SocketTimeoutException XML Parse Error http://x.x.x.x./descocket Open Failed java.nio.channels.ClosedSelectorException
Michel Kohanim Posted May 21, 2009 Posted May 21, 2009 Hi CJVann, Thanks for the explanations. The reason for socket timeout error is that ISY is in DOS mode. Something in your network is trying to login to ISY without the correct credentials. Do you have Network Magic? With kind regards, Michel CJVann, If dropping subscriptions were the case, and based on what I know from HS plugin, I expected to see a lot more -5012s. The dropped subscriptions were caused by the the electric blinking off. The HomeSeer computer was on a UPS, so it wouldn't lose power. The ISY would reboot due to the power loss and sometimes got a new IP address that was different from what HomeSeer was using, so they would lose communications. I took the HomeSeer computer off of the UPS so they both reboot and synch IP addresses whenever the power blinks off (happens frequently here). As far as not being able to get to ISY, can you at least get to the HTML page? What error do you see? I login to ISY at this address: http://www.universal-devices.com/99i It displays the "Please Keep This Window Open!" screen, then loads the Admin Console window but instead of the pop-up window for Username and password, approx. every 15 seconds it pops up 3 little error message windows for these error messages: Socket Opened Failed java.net.SocketTimeoutException XML Parse Error http://x.x.x.x./descocket Open Failed java.nio.channels.ClosedSelectorException
Michel Kohanim Posted May 21, 2009 Posted May 21, 2009 CJVann, In the error, is the IP address the IP address for your ISY or is it 0.0.0.0 ? With kind regards, Michel No, I don't have Network Magic
CJVann Posted May 21, 2009 Posted May 21, 2009 It looked to be the same as the ISY address. It definitely was not 0.0.0.0.
bpwwer Posted May 21, 2009 Posted May 21, 2009 CJVann, Have you changed the ISY's username/password from the default? If so, can you try resetting it back to the default and restart HomeSeer? It is looking like the function that generates the Authorization header from the username/password is failing to generate the correct encoding. Since the plug-in code is trying repeatedly to connect with this bad header, it eventually triggers the ISY's denial of service flag. After that happens, you can't log in. If we can confirm that it is related to the username or password, then we should be able to figure out what character is breaking the function (it's a Microsoft function) and I should be able to create a work-a-round.
CJVann Posted May 28, 2009 Posted May 28, 2009 Follow-up: I worked with Bob offline. Setting the username/pw to admin/admin made everything work normally, but when I changed it back, it errored out again. Bob suggested I set the plug-in's debug level to "ALL" and the second I did that, everything began working and has been working the last 4 days without issue - even after changing the debug level back to it's default level and changing the username & pw back. He suspects that there may have been something wrong in the plugin's ini file that got overwritten to the correct value when I changed the log level. A huge thanks to Bob for all of his help in fixing this!
Recommended Posts
Archived
This topic is now archived and is closed to further replies.