Frustration Obviation...
There are times when installing a MID server can be very frustrating. Most of the time, you edit the config.xml file, start it up, and off it goes. Sometimes, though, the danged thing isn't so cooperative — that's when you feel like our tech with the tiny ears at right.
Generally speaking, the most frustrating thing is that you've got no idea what's going on. You look at the MID server log, and there's just no clue in there. Your only out is to pore over the config.xml file and the configuration on the instance, searching for something — anything — that might be wrong. Or chew on your keyboard, whichever feels better and is more effective.
Well get ready to celebrate, because those days are over, starting with the next release. No longer will you need to wash the foul taste of your keyboard from your mouth. Break out the champagne and start dancing on the tables!
I'm going to take you through a MID server installation where I have deliberately screwed up just about everything that could possibly be screwed up. You'll see how the MID server log now tell me exactly what's wrong.
So the first time I try running my messed-up MID server, here's what I see in the MID server log:
10/10/11 09:51:07 (792) main Running under Java version: 1.6.0_2210/10/11 09:51:08 (346) main Initializing MID Server10/10/11 09:51:08 (472) MIDServer MID Server starting10/10/11 09:51:09 (125) MIDServer Using configuration: /glide/workspace/com.service_now.agent/work/config.xml10/10/11 09:51:10 (252) MIDServer Agent home path: /glide/workspace/com.service_now.agent10/10/11 09:51:10 (325) StartupSequencer Setting basic authentication with user mid_server10/10/11 09:51:10 (357) MIDServer MID Server started
10/10/11 09:51:10 (676) StartupSequencer SEVERE *** ERROR *** Problem invoking InstanceInfo on http://localhost:8081/snc/: IOException: Connection refused
The MID server stops right there, knowing that it can do nothing further until this issue is rectified. It will retry once per minute, hoping that in the meantime you've fixed the problem. In my case, it's just a dumb little typo: I typed port 8081 instead of 8080. I fixed the typo and restarted the MID server so that it would re-read the config.xml file. This could have been any kind of connectivity problem, however — a bad URL, a missing proxy configuration, a firewall issue, etc. The MID server, unfortunately, can't tell exactly what caused the connectivity issue, but it certainly can tell you that it's having one. And now it does!
So I fixed that problem and ran it again. Now I see this in the MID server log:
10/10/11 09:52:22 (358) main Running under Java version: 1.6.0_2210/10/11 09:52:22 (436) main Initializing MID Server10/10/11 09:52:22 (540) MIDServer MID Server starting10/10/11 09:52:22 (858) MIDServer Using configuration: /glide/workspace/com.service_now.agent/work/config.xml10/10/11 09:52:23 (660) MIDServer Agent home path: /glide/workspace/com.service_now.agent10/10/11 09:52:23 (677) StartupSequencer Setting basic authentication with user mid_server10/10/11 09:52:23 (762) MIDServer MID Server started10/10/11 09:52:24 (045) StartupSequencer Successfully connected to instance:10/10/11 09:52:24 (045) StartupSequencer Install name: Demo Server10/10/11 09:52:24 (045) StartupSequencer Instance name: unregistered10/10/11 09:52:24 (045) StartupSequencer Node: 677dc85b774fe69066fea969f1780d5210/10/11 09:52:24 (045) StartupSequencer Build date: 10-08-2011_210010/10/11 09:52:24 (045) StartupSequencer Build tag: glide-10-08-2011_210010/10/11 09:52:24 (045) StartupSequencer Instance ID: b1020d20a7120000dadaefd459acf41110/10/11 09:52:24 (046) StartupSequencer System ID: slightlyloony.service-now.com:glide10/10/11 09:52:24 (046) StartupSequencer Instance IP: 10.1.0.9910/10/11 09:52:24 (046) StartupSequencer MID version: 10-04-2011_1946
10/10/11 09:52:24 (075) StartupSequencer WARNING *** WARNING *** Could not authenticate user 'mid_server' on the ServiceNow instance
Again, the MID server stops at this point, and retries once a minute. Note that this time it logged a bunch of information about the instance I connected to — the idea there is to give you the information needed to verify that you've configured it to talk to the correct instance. Somehow I accidentally got that right. But now I've got a pretty clear warning on the bottom: the MID server couldn't authenticate the user ("mid_server") that I put into config.xml. There are several possible causes: the user is missing, its password doesn't match what I put in the config.xml, the user is inactive, etc. In my case, I simply forgot the user. So I added it, and tried again:
10/10/11 09:59:36 (047) main Running under Java version: 1.6.0_2210/10/11 09:59:36 (075) main Initializing MID Server10/10/11 09:59:36 (179) MIDServer MID Server starting10/10/11 09:59:36 (529) MIDServer Using configuration: /glide/workspace/com.service_now.agent/work/config.xml10/10/11 09:59:37 (454) MIDServer Agent home path: /glide/workspace/com.service_now.agent10/10/11 09:59:37 (470) StartupSequencer Setting basic authentication with user mid_server10/10/11 09:59:37 (555) MIDServer MID Server started10/10/11 09:59:37 (827) StartupSequencer Successfully connected to instance:10/10/11 09:59:37 (850) StartupSequencer Install name: Demo Server10/10/11 09:59:37 (850) StartupSequencer Instance name: unregistered10/10/11 09:59:37 (850) StartupSequencer Node: 677dc85b774fe69066fea969f1780d5210/10/11 09:59:37 (850) StartupSequencer Build date: 10-08-2011_210010/10/11 09:59:37 (850) StartupSequencer Build tag: glide-10-08-2011_210010/10/11 09:59:37 (850) StartupSequencer Instance ID: b1020d20a7120000dadaefd459acf41110/10/11 09:59:37 (850) StartupSequencer System ID: slightlyloony.service-now.com:glide10/10/11 09:59:37 (850) StartupSequencer Instance IP: 10.1.0.9910/10/11 09:59:37 (850) StartupSequencer MID version: 10-04-2011_194610/10/11 09:59:37 (954) StartupSequencer SOAP basic authentication is enabled10/10/11 09:59:37 (954) StartupSequencer SOAP strict security is enabled
10/10/11 09:59:37 (954) StartupSequencer WARNING *** WARNING *** Missing role from user mid_server: soap_ecc
Once again the MID server comes to a screeching halt, and will retry every minute until I get it right. What did I mess up this time? Well, I forgot to give my mid_server user the soap_ecc role, despite the documentation on the wiki that makes it abundantly clear that I should have. Sheesh, what a maroon! Fixed that, and tried again:
10/10/11 10:02:45 (065) main Running under Java version: 1.6.0_2210/10/11 10:02:45 (108) main Initializing MID Server10/10/11 10:02:45 (213) MIDServer MID Server starting10/10/11 10:02:45 (482) MIDServer Using configuration: /glide/workspace/com.service_now.agent/work/config.xml10/10/11 10:02:46 (290) MIDServer Agent home path: /glide/workspace/com.service_now.agent10/10/11 10:02:46 (326) StartupSequencer Setting basic authentication with user mid_server10/10/11 10:02:46 (393) MIDServer MID Server started10/10/11 10:02:46 (660) StartupSequencer Successfully connected to instance:10/10/11 09:02:46 (675) StartupSequencer Install name: Demo Server10/10/11 09:02:46 (675) StartupSequencer Instance name: unregistered10/10/11 09:02:46 (675) StartupSequencer Node: 677dc85b774fe69066fea969f1780d5210/10/11 09:02:46 (675) StartupSequencer Build date: 10-08-2011_210010/10/11 09:02:46 (675) StartupSequencer Build tag: glide-10-08-2011_210010/10/11 09:02:46 (675) StartupSequencer Instance ID: b1020d20a7120000dadaefd459acf41110/10/11 09:02:46 (675) StartupSequencer System ID: slightlyloony.service-now.com:glide10/10/11 09:02:46 (675) StartupSequencer Instance IP: 10.1.0.9910/10/11 09:02:46 (675) StartupSequencer MID version: 10-04-2011_194610/10/11 10:02:46 (751) StartupSequencer SOAP basic authentication is enabled10/10/11 10:02:46 (751) StartupSequencer SOAP strict security is enabled10/10/11 10:02:46 (751) StartupSequencer User mid_server has all necessary roles10/10/11 10:02:46 (771) File sync worker: ecc_agent_mib Starting file synchronization: ecc_agent_mib10/10/11 10:02:46 (787) StartupSequencer Enabling monitor: FileSyncer10/10/11 10:02:46 (788) File sync worker: ecc_agent_jar Starting file synchronization: ecc_agent_jar10/10/11 10:02:47 (001) File sync worker: ecc_agent_jar Finishing file synchronization: ecc_agent_jar10/10/11 10:02:47 (001) File sync worker: ecc_agent_mib Finishing file synchronization: ecc_agent_mib10/10/11 10:02:48 (838) StartupSequencer Getting instance ACLs for table: ecc_agent_property10/10/11 10:02:49 (116) StartupSequencer Getting instance ACLs for table: ecc_agent
10/10/11 10:02:49 (167) StartupSequencer WARNING *** WARNING *** Can't read because table ACL denies it: ecc_agent
This time the MID server doesn't stop — it keeps going, as I've now got enough configured correctly that it can function, albeit with some kind of issue caused by its inability to get to the ecc_agent table. I know this because the warning is telling me that the ACL (Access Control List) is not letting the MID server read the ecc_agent table. Anytime there's a missing ACL (System Security → Access Control) you'll see one of these warnings in the log. The impact of the ACL issues varies depending on the table and the type of ACL (read, write, etc.) that's missing. But one thing you can be certain of: if you see one of these warnings, then the ACLs on the instance need to be fixed, or something on the MID server ain't a-gonna work correctly. So I added the missing ACL and ran again:
10/10/11 10:03:54 (119) main Running under Java version: 1.6.0_2210/10/11 10:03:54 (336) main Initializing MID Server10/10/11 10:03:54 (497) MIDServer MID Server starting10/10/11 10:03:55 (067) MIDServer Using configuration: /glide/workspace/com.service_now.agent/work/config.xml10/10/11 10:03:56 (303) MIDServer Agent home path: /glide/workspace/com.service_now.agent10/10/11 10:03:56 (403) MIDServer MID Server started10/10/11 10:03:56 (438) StartupSequencer Setting basic authentication with user mid_server10/10/11 10:03:58 (798) StartupSequencer Successfully connected to instance:10/10/11 10:03:58 (799) StartupSequencer Install name: Demo Server10/10/11 10:03:58 (799) StartupSequencer Instance name: unregistered10/10/11 10:03:58 (799) StartupSequencer Node: 677dc85b774fe69066fea969f1780d5210/10/11 10:03:58 (799) StartupSequencer Build date: Sun_Oct_09_12_24_01_PDT_201110/10/11 10:03:58 (799) StartupSequencer Build tag:10/10/11 10:03:58 (799) StartupSequencer Instance ID: b1020d20a7120000dadaefd459acf41110/10/11 10:03:58 (799) StartupSequencer System ID: slightlyloony.dilatush.com:glide10/10/11 10:03:58 (799) StartupSequencer Instance IP: 10.179.0.9910/10/11 10:03:58 (799) StartupSequencer MID version: 10-04-2011_194610/10/11 10:03:59 (118) StartupSequencer SOAP basic authentication is enabled10/10/11 10:03:59 (118) StartupSequencer SOAP strict security is enabled10/10/11 10:03:59 (118) StartupSequencer User mid_server has all necessary roles10/10/11 10:03:59 (298) File sync worker: ecc_agent_mib Starting file synchronization: ecc_agent_mib10/10/11 10:03:59 (302) File sync worker: ecc_agent_jar Starting file synchronization: ecc_agent_jar10/10/11 10:03:59 (308) StartupSequencer Enabling monitor: FileSyncer10/10/11 10:04:00 (005) File sync worker: ecc_agent_jar Deleting /glide/workspace/com.service_now.agent/extlib/.cvsignore10/10/11 10:04:00 (036) File sync worker: ecc_agent_jar Deleting directory /glide/workspace/com.service_now.agent/extlib/CVS and all directories and files it contains10/10/11 10:04:00 (036) File sync worker: ecc_agent_mib Finishing file synchronization: ecc_agent_mib10/10/11 10:04:00 (125) File sync worker: ecc_agent_jar Finishing file synchronization: ecc_agent_jar10/10/11 10:04:01 (463) StartupSequencer Getting instance ACLs for table: ecc_agent_property10/10/11 10:04:02 (387) StartupSequencer Getting instance ACLs for table: ecc_agent10/10/11 10:04:02 (904) StartupSequencer Enabling monitor: RefreshMonitor10/10/11 10:04:03 (191) StartupSequencer Enabling monitor: ECCQueueMonitor10/10/11 10:04:03 (341) StartupSequencer Enabling monitor: ECCSender10/10/11 10:04:03 (374) StartupSequencer Enabling monitor: LogStatusMonitor10/10/11 10:04:03 (706) StartupSequencer Getting instance ACLs for table: ecc_queue10/10/11 10:04:03 (952) StartupSequencer Enabling monitor: StatusMonitor10/10/11 10:04:08 (486) StartupSequencer Loaded credentials provider: com.service_now.mid.creds.standard.StandardCredentialsProvider10/10/11 10:04:09 (096) StartupSequencer Public SNMP Credentials loaded10/10/11 10:04:09 (096) StartupSequencer Credentials from instance loaded10/10/11 10:04:09 (576) MIB Initializer Loading MIBs10/10/11 10:04:10 (751) StartupSequencer Getting instance ACLs for table: ecc_agent_script_include
10/10/11 10:04:12 (804) LogStatusMonitor.60 stats threads: 17, memory max: 263.0mb, allocated: 81.0mb, used: 5.0mb, queued: 0 probes, processing: 0 probes
Ah, now that's more like it! The MID server is up and running, with no reported problems. Woo hoo! That nasty-tasting keyboard is going in the trash!
https://www.servicenow.com/community/in-other-news/frustration-obviation/ba-p/2282858