07-30-2014 12:11 PM
I have the following C# code that works great most of the time but every once in a while CreateChannel will take 400+ms to return instead of the usual 3-4ms. I can reproduce this on at least two different computers / configurations.
Attached sample output from test program.
Any ideas?
Thanks
public long SetRangeDigitalOutput(string portID, string[] lineIDs, bool[] values, ref DateTime timeStamp) { Task digitalWriteTask = null; bool[] tmpValues; string chanelDescription = string.Empty; long timeBeforeCallingWriteSingleSampleMultiLine = 0; long timeAfterCallingWriteSingleSampleMultiLine = 0; long timeBeforeCreateChannel = 0; long timeAfterCreateChannel = 0; try { if (DOPorts.ContainsKey(portID)) { //build the chanelDescription string foreach (string line in lineIDs) { if (DOPorts[portID].Lines.ContainsKey(line)) { chanelDescription = chanelDescription + this.DeviceID + "/" + portID + "/line" + DOPorts[portID].Lines[line].LineNumber.ToString() + ","; } else { throw new ArgumentOutOfRangeException("endLineID", "Line: " + line + " is not available on device: " + this.DeviceID + " port: " + portID); } } chanelDescription = chanelDescription.TrimEnd(','); digitalWriteTask = new Task(); timeBeforeCreateChannel = debugTimer.ElapsedMilliseconds; chanel = digitalWriteTask.DOChannels.CreateChannel(chanelDescription, portID, ChannelLineGrouping.OneChannelForAllLines); timeAfterCreateChannel = debugTimer.ElapsedMilliseconds; writer = new DigitalSingleChannelWriter(digitalWriteTask.Stream); tmpValues = new bool[values.Length]; values.CopyTo(tmpValues, 0); timeStamp = DateTime.Now; timeBeforeCallingWriteSingleSampleMultiLine = debugTimer.ElapsedMilliseconds; writer.WriteSingleSampleMultiLine(true, tmpValues); timeAfterCallingWriteSingleSampleMultiLine = debugTimer.ElapsedMilliseconds; DebugMessage = " Time before creating DAQ channel = " + timeBeforeCreateChannel.ToString() + " Time after creating DAQ channel = " + timeAfterCreateChannel.ToString() + " Time before calling WriteSingleSampleMultiLine = " + timeBeforeCallingWriteSingleSampleMultiLine.ToString() + " Time after calling WriteSingleSampleMultiLine = " + timeAfterCallingWriteSingleSampleMultiLine.ToString(); } else { throw new ArgumentOutOfRangeException("portID", "Port: " + portID + " is not available on device: " + this.DeviceID); } } catch (Exception) { throw; } finally { writer = null; chanel = null; digitalWriteTask = null; } return (timeAfterCallingWriteSingleSampleMultiLine - timeBeforeCreateChannel); }
07-31-2014 05:13 PM
Hey jveisz
Is the increased time completely random each time you run your code or does it consistantly happen around the same trial?
You may want to put a wait function before the CreateChannel to make sure that the resource isn't reserved and everything has a chance to catch up.
08-01-2014 08:29 AM
I'm having a similar problem, and I can answer for jveisz- it's extremely consistent. Every time, the first (of eight) CreateChannel instructions is slow. I ran the program 40 times:
Hardware device: Virtual device: 1293 1275 1293 1274 1287 1273 1301 1273 1297 1273 1294 1274 1292 1274 1290 1273 1285 1274 1286 1274 1287 1276 1288 1274 1289 1275 1288 1274 1294 1275 1287 1287 1290 1274 1291 1275 1287 1273
These are the duration in milliseconds for the call. Both columns are for PCIe-6321 cards, one virtual and the other physical.
I declare analog input channels, digital input channels, and digital output channels, all in almost identical fashion, and they all take a very short time. Here's the offending line:
logger.Trace("Configuring channels")
Dim ch01 As DIChannel = Me.DIChannels.CreateChannel("Dev1/port0/line0", "DigitalIn_01", ChannelLineGrouping.OneChannelForEachLine)
logger.Trace("Configured ch01")
and here is the progress log:
frmSplash 09:02:46.8011 TRACE Splash form event (5): Loading National Instruments IO configuration file modNI 09:02:46.8181 TRACE Loading NI modNI 09:02:46.8181 TRACE 0: Declared variables modNI 09:02:46.8181 TRACE 0: Loaded section Machine Settings modNI 09:02:46.8181 TRACE 1: Loaded section Digital IO 00 - Input modNI 09:02:46.8181 TRACE 1: Loaded section Digital IO 01 - Input modNI 09:02:46.8181 TRACE 1: Loaded section Digital IO 02 - Input modNI 09:02:46.8181 TRACE 1: Loaded section Digital IO 03 - Input modNI 09:02:46.8181 TRACE 1: Loaded section Digital IO 04 - Input modNI 09:02:46.8181 TRACE 2: Loaded section Digital IO 05 - Input modNI 09:02:46.8181 TRACE 2: Loaded section Digital IO 06 - Input modNI 09:02:46.8181 TRACE 2: Loaded section Digital IO 07 - Input modNI 09:02:46.8181 TRACE 2: Loaded section Digital IO 08 - Output modNI 09:02:46.8271 TRACE 2: Loaded section Digital IO 09 - Output modNI 09:02:46.8271 TRACE 3: Loaded section Digital IO 10 - Output modNI 09:02:46.8271 TRACE 4: Loaded section Digital IO 11 - Output modNI 09:02:46.8271 TRACE 4: Loaded section Digital IO 12 - Output modNI 09:02:46.8271 TRACE 4: Loaded section Digital IO 13 - Output modNI 09:02:46.8271 TRACE 4: Loaded section Digital IO 14 - Output modNI 09:02:46.8271 TRACE 4: Loaded section Digital IO 15 - Output modNI 09:02:46.8271 TRACE 6: Loaded section Analog Input 00 modNI 09:02:46.8271 TRACE 6: Loaded section Analog Input 00 - Calibration modNI 09:02:46.8271 TRACE 7: Loaded section Analog Input 01 modNI 09:02:46.8271 TRACE 7: Loaded section Analog Input 01 - Calibration modNI 09:02:46.8271 TRACE 7: Loaded section Analog Input 02 modNI 09:02:46.8271 TRACE 7: Loaded section Analog Input 02 - Calibration modNI 09:02:46.8271 TRACE 7: Loaded section Analog Input 03 modNI 09:02:46.8271 TRACE 7: Loaded section Analog Input 03 - Calibration modNI 09:02:46.8271 TRACE 7: Loaded section Analog Input 04 modNI 09:02:46.8271 TRACE 7: Loaded section Analog Input 04 - Calibration modNI 09:02:46.8271 TRACE 8: Loaded section Analog Input 05 modNI 09:02:46.8271 TRACE 8: Loaded section Analog Input 05 - Calibration modNI 09:02:46.8271 TRACE 8: Loaded section Analog Input 06 modNI 09:02:46.8271 TRACE 8: Loaded section Analog Input 06 - Calibration modNI 09:02:46.8271 TRACE 8: Loaded section Analog Input 07 modNI 09:02:46.8271 TRACE 8: Loaded section Analog Input 07 - Calibration modNI 09:02:46.8271 TRACE 8: Loaded section Analog Output 00 modNI 09:02:46.8271 TRACE 8: Loaded section Analog Output 01 modNI 09:02:46.8271 TRACE 9: Declared AIControl modNI 09:02:46.8271 TRACE 13: Loaded analogInput 0 modNI 09:02:46.8271 TRACE 14: Loaded analogInput 1 modNI 09:02:46.8271 TRACE 14: Loaded analogInput 2 modNI 09:02:46.8431 TRACE 19: Loaded analogInput 3 modNI 09:02:46.8431 TRACE 19: Done loading AIControl uctrlDigitalInput 09:02:46.8431 TRACE Loading uctrlDigitalInput uctrlDigitalInput 09:02:46.8761 TRACE Declaring daqmxTask tskDigitalInput 09:02:46.9061 TRACE Loaded MyBase.New(tskDigitalInput) tskDigitalInput 09:02:46.9061 TRACE Configuring tskDigitalInput # Here is where the execution waits for 1300+ milliseconds tskDigitalInput 09:02:46.9061 TRACE Configuring channels tskDigitalInput 09:02:48.1831 TRACE Configured ch01 tskDigitalInput 09:02:48.1831 TRACE Configured ch02 tskDigitalInput 09:02:48.1831 TRACE Configured ch03 tskDigitalInput 09:02:48.1841 TRACE Configured ch04 tskDigitalInput 09:02:48.1841 TRACE Configured ch05 tskDigitalInput 09:02:48.1841 TRACE Configured ch06 tskDigitalInput 09:02:48.1841 TRACE Configured ch07 tskDigitalInput 09:02:48.1841 TRACE Configured ch08 tskDigitalInput 09:02:48.1841 TRACE Done configuring channels tskDigitalInput 09:02:48.1841 TRACE Setting InvertLines tskDigitalInput 09:02:48.1841 TRACE Done setting InvertLines tskDigitalInput 09:02:48.1841 TRACE Done configuring tskDigitalInput uctrlDigitalInput 09:02:48.1841 TRACE Done declaring daqmxTask uctrlDigitalInput 09:02:48.1841 TRACE Declaring daqmxReader uctrlDigitalInput 09:02:48.1841 TRACE Done declaring daqmxReader uctrlDigitalInput 09:02:48.1841 TRACE Done loading uctrlDigitalInput modNI 09:02:48.1841 TRACE 1364: Declared DIControl modNI 09:02:48.1841 TRACE 1365: Loaded digitalInput 0 modNI 09:02:48.1841 TRACE 1365: Loaded digitalInput 1 modNI 09:02:48.1841 TRACE 1365: Loaded digitalInput 2 modNI 09:02:48.1841 TRACE 1365: Loaded digitalInput 3 modNI 09:02:48.1841 TRACE 1365: Loaded digitalInput 4 modNI 09:02:48.1841 TRACE 1366: Loaded digitalInput 5 modNI 09:02:48.1841 TRACE 1366: Loaded digitalInput 6 modNI 09:02:48.1841 TRACE 1366: Loaded digitalInput 7 modNI 09:02:48.1841 TRACE 1370: Declared DOControl modNI 09:02:48.1841 TRACE 1370: Loaded digitalInput 0 modNI 09:02:48.1841 TRACE 1371: Loaded digitalInput 1 modNI 09:02:48.1841 TRACE 1371: Loaded digitalInput 2 modNI 09:02:48.1841 TRACE 1371: Loaded digitalInput 3 modNI 09:02:48.1841 TRACE 1371: Loaded digitalInput 4 modNI 09:02:48.1841 TRACE 1371: Loaded digitalInput 5 modNI 09:02:48.1841 TRACE 1374: Loaded digitalInput 6 modNI 09:02:48.1841 TRACE 1374: Loaded digitalInput 7 modNI 09:02:48.1841 TRACE 1374: Done with LoadNI frmSplash 09:02:48.1841 TRACE Splash form event (6): IO configuration and calibration loaded
The initialization code is much the same as jveisz's code, but I can post it if that would help.
08-01-2014 12:03 PM
kvermeer you are correct. The first call to CreateChannel and WriteSingleSampleMultiline takes longer for me as well. About 60ms for the first CreateChannel and another 80ms or so for the write.
I'm using an NI-9476 in a cDAQ9174 base. However if you change your program to call CreateChannel about 600 times instead of just 8 you should see other instances where CreateChannel takes longer.
Maxwell,
The timing seems random to me. It happens once in about every 500 calls. How long should I wait before calling CreateChannel? Not sure if that will help but I'm willing to give it a try.
08-01-2014 12:09 PM - edited 08-01-2014 12:24 PM
Once in 500 tries? Interesting. My code is structured to only make the call once, at startup, so I've only seen it as occurring the first time, every time. I've been ignoring the issue for a while: It's by far the longest thing in the startup sequence, but we can tolerate it. However, it would be great to be able to remove it.
I'll see if I can throw together a minimal example program that will do it.
08-01-2014 03:25 PM
Here's a small example program which reproduces the issue, which occurs on Line 50 of niDigitalInputs.vb.
08-12-2014 01:03 PM
Does anyone know how to fix this problem? Has anyone else observed it?
08-13-2014 08:28 PM
Hey kvermeer,
I tried to run your example program that you’ve written but I’m not able to find where the data is logged to by this line
logger.Debug("DI Channel 1 CreateChannel time is {0}", sw.ElapsedMilliseconds)
Can you also tell me what hardware you are using to try and replicate this issue as close as I can?
08-14-2014 06:45 AM
Hi Taylor,
Thanks for looking into this.
The logger.Debug lines are referencing a logging package called NLog, and NLog.config specifies that the output goes into %AppData%/NI Init Demo/logs/shortdate.log (or C:\Users\user\AppData\Roaming\Schap Specialty Machine\NI Init Demo\logs\shortdate.log on my machine). You can also use a monitoring program like Log2Console on udp://127.0.0.1:9999.
I'm using a PCIe-6321 card, but I've seen it on other cards like the PCIe-6320s and PCI-6503.
--
Kevin Vermeer
08-15-2014 02:13 PM
Hey kvermeer,
Thanks for sending that file path location, I would have never been able to find it on my own. Unfortunately I'm not able to reproduce what you're seeing though. The example program that you posted seems work pretty consistantly. I'm wondering if this could just be do to the system you're running on. I'm including the log file that was generated while running your example program. I ran it about 20 times or so.