Program Info is Blank
John Gonzales
Junior Member
in AMX Hardware
I've got an NI-3100 that's been running fine for about 2 years, the last programming update to it was done 14 months ago. All of the sudden, after having unplugged the unit for about 10 minutes, the master is no longer functioning properly. Here are the symptoms:
The unit is online, device number, system number, everything is fine. I can telnet into it, the touchpanel connects to it, it's in a master-master network and it can see and be seen by the other masters. Diagnostics, Notifications all work -- BUT, it appears as though there's no program loaded in it anymore. When I telnet in and execute the 'program info' command, I get a response as though nothing's in there. I loaded a small 2 line program to send a diagnostic message every 10 seconds and that loads and functions fine. Executing a 'program info' command returns the program name. When I load the program that's been in there for 2 years, we're back to the original symptoms as though there's no program loaded.
I've issued clean disk commands, reloaded firmware, changed the name of the program, boosted the duet memory up, commented out the duet modules that were in there... any ideas what to check next? One thing too is that I think the CMOS battery may be bad, since we've been having issues with the time and date falling behind lately.
Thanks for reading this long post.
--John
The unit is online, device number, system number, everything is fine. I can telnet into it, the touchpanel connects to it, it's in a master-master network and it can see and be seen by the other masters. Diagnostics, Notifications all work -- BUT, it appears as though there's no program loaded in it anymore. When I telnet in and execute the 'program info' command, I get a response as though nothing's in there. I loaded a small 2 line program to send a diagnostic message every 10 seconds and that loads and functions fine. Executing a 'program info' command returns the program name. When I load the program that's been in there for 2 years, we're back to the original symptoms as though there's no program loaded.
I've issued clean disk commands, reloaded firmware, changed the name of the program, boosted the duet memory up, commented out the duet modules that were in there... any ideas what to check next? One thing too is that I think the CMOS battery may be bad, since we've been having issues with the time and date falling behind lately.
Thanks for reading this long post.
--John
Comments
Format Disk doesn't seem to work either by the way, only clean disk. Is that command still supported?
--John
Was this code recompiled or is it the original .tkn file you're trying to download?
I don't see any obvious errors in the startup logs. Memory seems to be o.k., and using a get mem command it shows plenty of space too.
When I reloaded the program, I first reloaded the original .tkn, then I recompiled it and loaded the new .tkn, then I saved the program as a different name, recompiled and loaded that .tkn. Same issue occurred with all of those files -- no program info. The only one that showed up and functioned correctly was my little 2 line program.
Here's a copy of the log in case I didn't see something. I have to admit, I don't understand a lot of what the logs indicate unless it's glaringly obvious.
--John
=~=~=~=~=~=~=~=~=~=~=~= PuTTY log 2008.07.31 09:40:06 =~=~=~=~=~=~=~=~=~=~=~= >program info -- Program Name Info >show mem Volatile Free : 23993312 (largest free block in bytes) NonVolatile Free: 1047536 (bytes free) Disk Free :120139776 (bytes of free space) Duet Memory Free : 6990848 (bytes) Partition 1 - 6990848 (bytes) Partition 2 - <UNKNOWN> >show log all Message Log for System 3 Version: v3.30.371 Entry Date/Time Object Text --------------------------------------------------------------------------- 1: 06-06-2008 FRI 01:12:55 TelnetSvr Accepted Telnet connection:socket=31 addr=192.168.110.79 port=3351 2: 06-06-2008 FRI 01:11:40 TelnetSvr Accepted Telnet connection:socket=31 addr=192.168.110.79 port=3348 3: 06-06-2008 FRI 01:11:37 Unknown DDD.handleDynamicDevice(): new DPD - 192.168.110.23 4: 06-06-2008 FRI 01:10:56 ConnectionManager Memory Available = 23998408 <25232> 5: 06-06-2008 FRI 01:10:56 Unknown IPDeviceDetector.run(): joined multicast group 6: 06-06-2008 FRI 01:10:10 ConnectionManager Memory Available = 24023640 <81248> 7: 06-06-2008 FRI 01:10:10 TelnetSvr Accepted Telnet connection:socket=31 addr=192.168.110.79 port=3343 8: 06-06-2008 FRI 01:09:47 Unknown (Reader=(null) writer=tDeviceMgr)- CMessagePipe::Max = 75 9: 06-06-2008 FRI 01:09:47 Unknown (Reader=(null) writer=tDeviceMgr)- CMessagePipe::Max = 50 10: 06-06-2008 FRI 01:09:37 RouteManager Remote System 11 Online: Route 1 Metric 2 11: 06-06-2008 FRI 01:09:37 RouteManager Remote System 10 Online: Route 1 Metric 2 12: 06-06-2008 FRI 01:09:37 RouteManager Remote System 7 Online: Route 1 Metric 2 13: 06-06-2008 FRI 01:09:37 RouteManager Remote System 5 Online: Route 1 Metric 2 14: 06-06-2008 FRI 01:09:37 RouteManager Remote System 4 Online: Route 1 Metric 2 15: 06-06-2008 FRI 01:09:37 RouteManager Remote System 2 Online: Route 1 Metric 2 16: 06-06-2008 FRI 01:09:37 RouteManager Remote System 1 Online: Route 1 Metric 1 17: 06-06-2008 FRI 01:09:37 ConnectionManager Memory Available = 24104888 <38168> 18: 06-06-2008 FRI 01:09:36 ConnectionManager Memory Available = 24143056 <44160> 19: 06-06-2008 FRI 01:09:36 ConnectionManager Memory Available = 24187216 <69184> 20: 06-06-2008 FRI 01:09:36 Unknown (Reader=tDeviceMgr writer=tConnectMgr)- CMessagePipe::Max = 50 21: 06-06-2008 FRI 01:09:36 ConnectionManager Memory Available = 24256400 <82328> 22: 06-06-2008 FRI 01:09:36 Unknown (Reader=tConnectMgr writer=ICSPTCPRx29)- CMessagePipe::Max = 50 23: 06-06-2008 FRI 01:09:36 Unknown (Reader=(null) writer=tDeviceMgr)- CMessagePipe::Max = 25 24: 06-06-2008 FRI 01:09:36 Unknown (Reader=tDeviceMgr writer=tConnectMgr)- CMessagePipe::Max = 25 25: 06-06-2008 FRI 01:09:36 Unknown (Reader=tConnectMgr writer=ICSPTCPRx29)- CMessagePipe::Max = 25 26: 06-06-2008 FRI 01:09:36 ConnectionManager Memory Available = 24338728 <38224> 27: 06-06-2008 FRI 01:09:33 ConnectionManager Memory Available = 24376952 <251080> 28: 06-06-2008 FRI 01:09:33 Unknown 01:09:33.299 EVENT Started org.mortbay.jetty.Server@7943b6 29: 06-06-2008 FRI 01:09:33 Unknown 01:09:33.299 EVENT Started SocketListener on 0.0.0.0:443 30: 06-06-2008 FRI 01:09:32 ConnectionManager Memory Available = 24628032 <246304> 31: 06-06-2008 FRI 01:09:32 Unknown 01:09:32.449 EVENT Started SocketListener on 0.0.0.0:83 32: 06-06-2008 FRI 01:09:32 Unknown 01:09:32.233 EVENT Starting Jetty/4.2.x 33: 06-06-2008 FRI 01:09:32 Unknown DynamicServlet 0.0.1 has been started 34: 06-06-2008 FRI 01:09:32 Unknown 01:09:32.183 EVENT Started ServletHttpContext[/] 35: 06-06-2008 FRI 01:09:31 ConnectionManager Memory Available = 24874336 <90240> 36: 06-06-2008 FRI 01:09:31 Unknown SecurityServlet 0.0.1 has been started 37: 06-06-2008 FRI 01:09:31 Unknown 01:09:31.699 EVENT Started ServletHttpContext[/] 38: 06-06-2008 FRI 01:09:31 Unknown ConfigServlet 0.0.1 has been started 39: 06-06-2008 FRI 01:09:31 Unknown 01:09:31.033 EVENT Started ServletHttpContext[/] 40: 06-06-2008 FRI 01:09:30 ConnectionManager Memory Available = 24964576 <193632> 41: 06-06-2008 FRI 01:09:30 ConnectionManager Memory Available = 25158208 <156416> 42: 06-06-2008 FRI 01:09:30 Unknown DeviceServlet 0.0.1 has been started 43: 06-06-2008 FRI 01:09:30 Unknown 01:09:30.499 EVENT Started ServletHttpContext[/] 44: 06-06-2008 FRI 01:09:30 Unknown RootServlet 0.0.1 has been started 45: 06-06-2008 FRI 01:09:30 Unknown 01:09:30.049 EVENT Started ServletHttpContext[/] 46: 06-06-2008 FRI 01:09:29 ConnectionManager Memory Available = 25314624 <130416> 47: 06-06-2008 FRI 01:09:29 Unknown 01:09:29.533 EVENT Started ServletHttpContext[/] 48: 06-06-2008 FRI 01:09:29 Unknown 01:09:28.866 EVENT Started ServletHttpContext[/] 49: 06-06-2008 FRI 01:09:28 ConnectionManager Memory Available = 25445040 <158888> 50: 06-06-2008 FRI 01:09:27 ConnectionManager Memory Available = 25603928 <79424> 51: 06-06-2008 FRI 01:09:26 ConnectionManager Memory Available = 25683352 <111472> 52: 06-06-2008 FRI 01:09:26 Unknown DynamicDeviceDetector 0.0.1 has been started 53: 06-06-2008 FRI 01:09:25 ConnectionManager Memory Available = 25794824 <65016> 54: 06-06-2008 FRI 01:09:25 ConnectionManager Memory Available = 25859840 <14080> 55: 06-06-2008 FRI 01:09:25 ConnectionManager Memory Available = 25873920 <79096> 56: 06-06-2008 FRI 01:09:25 ConnectionManager Memory Available = 25953016 <98640> 57: 06-06-2008 FRI 01:09:24 ConnectionManager Memory Available = 26051656 <130456> 58: 06-06-2008 FRI 01:09:24 Unknown DeviceAccess 0.0.1 has been started 59: 06-06-2008 FRI 01:09:23 ConnectionManager Memory Available = 26182112 <54680> 60: 06-06-2008 FRI 01:09:22 Unknown DeviceManager 0.0.1 has been started 61: 06-06-2008 FRI 01:09:22 ConnectionManager Memory Available = 26236792 <238392> 62: 06-06-2008 FRI 01:09:21 ConnectionManager Memory Available = 26475184 <93328> 63: 06-06-2008 FRI 01:09:20 ConnectionManager Memory Available = 26568512 <190536> 64: 06-06-2008 FRI 01:09:19 ConnectionManager Memory Available = 26759048 <27464> 65: 06-06-2008 FRI 01:09:18 ConnectionManager Memory Available = 26786512 <138680> 66: 06-06-2008 FRI 01:09:17 Unknown Create Jetty Web Server 67: 06-06-2008 FRI 01:09:17 ConnectionManager Memory Available = 26925192 <85632> 68: 06-06-2008 FRI 01:09:16 ConnectionManager Memory Available = 27010824 <146992> 69: 06-06-2008 FRI 01:09:16 ConnectionManager Memory Available = 27157816 <96688> 70: 06-06-2008 FRI 01:09:15 ConnectionManager Memory Available = 27254504 <138536> 71: 06-06-2008 FRI 01:09:14 Unknown ================= 72: 06-06-2008 FRI 01:09:14 Unknown Welcome to Duet. 73: 06-06-2008 FRI 01:09:14 ConnectionManager Memory Available = 27393040 <19952> 74: 06-06-2008 FRI 01:09:14 ConnectionManager Memory Available = 27412992 <22348640> 75: 06-06-2008 FRI 01:09:12 InternalMessageRouter Preparing to initialize java.lang.Thread 76: 06-06-2008 FRI 01:09:12 Unknown (0000006275) Preparing to initialize java.lang.Thread 77: 06-06-2008 FRI 01:09:12 InternalMessageRouter Preparing to initialize java.lang.ClassLoader$NativeLibrary 78: 06-06-2008 FRI 01:09:12 Unknown (0000006274) Preparing to initialize java.lang.ClassLoader$NativeLibrary 79: 06-06-2008 FRI 01:09:12 InternalMessageRouter Preparing to initialize java.lang.ClassLoader 80: 06-06-2008 FRI 01:09:12 Unknown (0000006273) Preparing to initialize java.lang.ClassLoader 81: 06-06-2008 FRI 01:09:12 InternalMessageRouter Preparing to initialize java.lang.Shutdown 82: 06-06-2008 FRI 01:09:12 Unknown (0000006273) Preparing to initialize java.lang.Shutdown 83: 06-06-2008 FRI 01:09:12 InternalMessageRouter Preparing to initialize sun.misc.ThreadRegistry 84: 06-06-2008 FRI 01:09:12 Unknown (0000006272) Preparing to initialize sun.misc.ThreadRegistry 85: 06-06-2008 FRI 01:09:12 InternalMessageRouter Preparing to initialize java.lang.String 86: 06-06-2008 FRI 01:09:12 Unknown (0000006272) Preparing to initialize java.lang.String 87: 06-06-2008 FRI 01:09:12 InternalMessageRouter Preparing to initialize java.lang.Float 88: 06-06-2008 FRI 01:09:12 Unknown (0000006271) Preparing to initialize java.lang.Float 89: 06-06-2008 FRI 01:09:12 InternalMessageRouter Preparing to initialize java.lang.Class 90: 06-06-2008 FRI 01:09:12 Unknown (0000006269) Preparing to initialize java.lang.Class 91: 06-06-2008 FRI 01:09:12 Unknown JVM Logger Thread Started 92: 06-06-2008 FRI 01:09:12 Interpreter CIpPersistent::SaveOldVariable 93: 06-06-2008 FRI 01:09:12 Interpreter CIpListMan::LoadVolatile 6168 1 94: 06-06-2008 FRI 01:09:12 Interpreter CIpCodeMan::LoadCode 13178 1 95: 06-06-2008 FRI 01:09:12 Interpreter CIpUffHandler::Module Header 96: 06-06-2008 FRI 01:09:12 Interpreter CIpUffHandler::Project Name=New 97: 06-06-2008 FRI 01:09:12 Interpreter CIpUffHandler::Root 98: 06-06-2008 FRI 01:09:12 Interpreter CIpUffHandler::Load - Begin...doc:PROG.TKN 99: 06-06-2008 FRI 01:09:12 Interpreter CIpNvMemory::NvInitalize NvRam Tested OK Used=1047536 Available=0 100: 06-06-2008 FRI 01:09:12 ConnectionManager Memory Available = 49761632 <231160> 101: 06-06-2008 FRI 01:09:12 Interpreter CIpInterpreter::Run - Unlocking Interpreter Mutex Early (Device Hold off is off) 102: 06-06-2008 FRI 01:09:14 ConnectionManager Memory Available = 49883768 103: 06-06-2008 FRI 01:09:09 ConfigurationManager JVMStartParam(2): -Djava.security.manager -Doscar.profile.name=Duet org.ungoverned.oscar.Main 104: 06-06-2008 FRI 01:09:09 ConfigurationManager JVMStartParam(1): v1.1 runJava -XsafeExit -Xms20M -Dpath.separator=; -Djava.class.path=doc:/lib;doc:/lib/Oscar.jar 105: 06-06-2008 FRI 01:09:09 ConfigurationManager UDP Blink Message Time = 5 seconds (0=off) 106: 06-06-2008 FRI 01:09:09 ConfigurationManager Log Entry Count = 1000 107: 06-06-2008 FRI 01:09:09 ConfigurationManager TCP Timeout = 45000mS 108: 06-06-2008 FRI 01:09:09 ConfigurationManager NetLinx Sockets Message Queue Size = 50 109: 06-06-2008 FRI 01:09:09 ConfigurationManager PhastLink Receive Message Queue Size = 500 110: 06-06-2008 FRI 01:09:09 ConfigurationManager ICSNet Receive Message Queue Size = 200 111: 06-06-2008 FRI 01:09:09 ConfigurationManager LontalkHost Message Queue Size = 500 112: 06-06-2008 FRI 01:09:09 ConfigurationManager Lontalk Message Queue Size = 500 113: 06-06-2008 FRI 01:09:09 ConfigurationManager UDP Transmit Message Queue Size = 500 114: 06-06-2008 FRI 01:09:09 ConfigurationManager ICSP 232 Transmit Message Queue Size = 500 115: 06-06-2008 FRI 01:09:09 ConfigurationManager ICSNet Transmit Message Queue Size = 500 116: 06-06-2008 FRI 01:09:09 ConfigurationManager PhastLink Transmit Message Queue Size = 500 117: 06-06-2008 FRI 01:09:09 ConfigurationManager Axlink Transmit Message Queue Size = 800 118: 06-06-2008 FRI 01:09:09 ConfigurationManager Message Dispatcher Message Queue Size = 1000 119: 06-06-2008 FRI 01:09:09 ConfigurationManager IP Connection Manager Message Queue Size = 800 120: 06-06-2008 FRI 01:09:09 ConfigurationManager TCP Transmit Threads Message Queue Size = 600 121: 06-06-2008 FRI 01:09:09 ConfigurationManager Diagnostic Manager Message Queue Size = 500 122: 06-06-2008 FRI 01:09:09 ConfigurationManager Device Manager Message Queue Size = 1500 123: 06-06-2008 FRI 01:09:09 ConfigurationManager Route Manager Message Queue Size = 400 124: 06-06-2008 FRI 01:09:09 ConfigurationManager Connection Manager Message Queue Size = 2000 125: 06-06-2008 FRI 01:09:09 ConfigurationManager Notification Manager Message Queue Size = 2000 126: 06-06-2008 FRI 01:09:09 ConfigurationManager Interpreter Message Queue Size = 2000 127: 06-06-2008 FRI 01:09:09 ConfigurationManager Routing Flags = $0 128: 06-06-2008 FRI 01:09:09 ConfigurationManager AMX URL = www.amx.com 129: 06-06-2008 FRI 01:09:09 ConfigurationManager CRL Check level = 0 130: 06-06-2008 FRI 01:09:09 ConfigurationManager IPSec Enabled = 0 131: 06-06-2008 FRI 01:09:09 ConfigurationManager Timeline Loopcnt = 10 132: 06-06-2008 FRI 01:09:09 ConfigurationManager IP Threshold = 1500 133: 06-06-2008 FRI 01:09:09 ConfigurationManager Lontalk Threshold = 50 134: 06-06-2008 FRI 01:09:09 ConfigurationManager Interpreter Threshold = 1500 135: 06-06-2008 FRI 01:09:09 ConfigurationManager Device Holdoff = 0 136: 06-06-2008 FRI 01:09:09 ConfigurationManager URL Entry[0] = 192.168.110.81:1319 (TCP) 137: 06-06-2008 FRI 01:09:09 ConfigurationManager URL Entry Count = 1 138: 06-06-2008 FRI 01:09:09 ConfigurationManager DNS Entry[0] = 192.168.110.100 139: 06-06-2008 FRI 01:09:09 ConfigurationManager DNS Entry Count = 1 140: 06-06-2008 FRI 01:09:09 ConfigurationManager Domain Name = 141: 06-06-2008 FRI 01:09:09 ConfigurationManager Serial Number = '210505x4561069' 142: 06-06-2008 FRI 01:09:09 ConfigurationManager System = 3 143: 06-06-2008 FRI 01:09:09 ConfigurationManager LoadConfiguration Complete (26920). >When I've encountered this behaviour it's always been because I've inadvertently forgotten to declare a large variable as volatile and have run out of non-volatile memory on the controller. I suspect the same may happen if the program has variable declarations which would exceed the amount of available RAM.
A "show mem" (I think, I can never remember terminal commands unless I'm in front of the box) should indicate if this is the case - check if any of the available memory sizes are negative.
Even though this doesn't explain why the problem is occurring on a system that's been running for 14 months without any changes to the program...
Edit: What's up with the event log you posted? I've never seen it garbled like that before.
When I do a show mem, it still shows that I have memory available, but I tried commenting out the duet modules just to help reduce the size, and the problem was still there. The weird thing like Auser pointed out, is that the program has been stable and running fine for over a year. The only thing that we can tie to the problem is that we had to remove power at that location for about 10 minutes and the CMOS battery seems to be going bad since the time/date drifts now. I'll load the program onto another master later today, but I'm confident it will work o.k.
Is there something else I should consider or can check on the software/setup side? I'll have one of our techs change out the CMOS battery too. If I recall correctly, when the CMOS battery is bad, that can cause issues with the BIOS and the memory pointers, etc..
I can't say it enough, but thanks again for all the help too!
--John
There is no non-volatile memory available. Look at variables that are not declared as VOLATILE. See if any can be set as VOLATILE.
Also, disable any modules that you didn't write.
Hmmm. This particular program is fairly small. It doesn't have any variables declared as non_volatile or persistent. Just to make sure though (since I didn't see that line you quoted until you posted it!) I declared every variable and constant specifically as volatile.
I commented those out too. And just for good measure I commented out the ones I wrote
I reloaded the program with the variables declared volatile, all modules commented out and still the same issue. I ran a show log all again and it still says
The time has also slipped over an hour since I reset it this morning (I'm feeling like a dog with a bone regarding the CMOS thing).
--John
After we uninstalled it, replaced it, and took it to the shop to troubleshoot the problem it naturally went away. I'm sure the switch got toggled a few times in the shop and they may have slapped it around a bit, but it did start working again.
FYI. You have to have at least one variable that is non_volatile or the code wont run.
Don't know why the system would stop all of a sudden after a reboot though.
It's going back for a new motherboard.
Maybe you have a similar problem.
As far as I know, the only reason you need to have one non-volatile variable is so that the debugger will function properly. The code will not have any problems other than those that are coded in if everything in volatile, you will just have problems monitoring variables in debug.
Jeff
I have a test program running on a 2nd master w/o any vars and the code works fine. Doesn't do much but it does what is supposed to. Open debug and I get a warning stating the compiled tkn doesn't match the source code which is BS cuz it's what I just uploaded. If I continue and open debug and drop a defined dev in nothing happens, no D:P:S displayed.
If I put in a VOLATILE var into the code the same thing happens and the var which was initiated to 1 shows nothing when dropped into the debug window. Now if I then change the VOLATILE var to NON_VOLATILE the warning pop up no longer appears, placing a defined dev into debug reveils its D:P:S and then placing the vars into debug show it has a value of 1.
So basically you do need at least one NON_VOLATILE var for debug to work but the code appears to function properly regardless.
Regarding the CMOS battery that I mentioned in every post, it doesn't seem to make any difference. As a matter of fact the NI-3100 that's been there for 2 years was shipped without the battery!
At this point the unit is with me and I'll try different things to make it come back to life before I RMA it to AMX. I feel special since I noticed several of the respondents were registered in 2004 and earlier (I still don't know how Dan C. registered more than a year before all of us
Thanks again everyone! I'll keep everyone apprised if I find out anything else new.
--John
Oh, there is a battery, just not a CR2032 or similar that your used to seeing. It's the big yellow block below the CF slot. And from what you have described, I'd bet your best bet is to get an RMA.
No, it really shipped without one. I pulled the yellow snaphat off of a 4100, then went into this 3100 and found that it was never installed. The timekeeper chip had the holes exposed where the snaphat was supposed to go. I know what I was looking for, and really - it wasn't there. Thanks for the RMA advice, I'll try a few more things this weekend before I send it back.
--John
Just for the benefit of any folks out there who aren't aware, global variables in NetLinx code are non-volatile unless declared otherwise.