Using the opcresponse.log, opcscan.log, and opcrefresh.log Files
In order to use the opcresponse.log, opcscan.log, and opcrefresh.log files, it is useful to understand the basic interface architecture. In simplistic terms, the interface has two threads of operation and a shared queue. One thread, often called the PI thread, interacts with the PI server while the other thread, often called the COM thread, interacts with the OPC server. During typical operation with polled tags, the PI thread will start the data collection process once the interface notifies the PI thread that it’s time to scan. At this point, the PI thread will log the time in opcscan.log, along with the group number and the current value of the flag for the group, and then sets the flag so the COM thread will see it.
opcscan.log: flag: time group
0: 1BFD631E7C98AF0 2
A major clue is that the flag in opcscan.log should never be anything but zero – if it’s not zero, then the last call made to the server has not retuned by the time the interface decided it was time for another poll.
The COM thread sees there’s a flag set, so it logs the time in the opcrefresh.log, file and then makes a Refresh call (when polling) to the OPC server, and finally clears the flag once it receives the synchronous response from the OPC server. The group number and transaction ID for the call are also logged.
It is important to note that the flag is not cleared until the call is completed (i.e. until the OPC server responds to the Refresh call).
Once the Refresh call has been, the OPC server can send data anytime in an asynchronous manner. When data is sent to the COM thread in the interface from the OPC server, the time is logged in opcresponse.log along with the group number and the transaction ID.
opcresponse.log: time group TransID
1BFD63208D4DCE0 2 1db8
The above discussion is only valid for polled points. Advise tags operate in a different manner, and the COM thread will only receive callbacks when the data from OPC server changes value. Therefore, Advise tags will NOT generate any entries in the opcscan.log or opcrefresh.log file and only the data callbacks will appear as entries in the opcresponse.log file as just described. As discussed earlier in the manual, Advise tags have group numbers ranging from 200 to 800 and therefore the callbacks to the opcresponse.log file are easily identifiable by noting the group number.
The timestamps in all of these files are logged just the way they are used in the program, so there are three programs that will translate those files. The interface does not translate the timestamps before it writes to the log files because that would take time and the problem is to determine how long it takes to get data. The three programs are installed into the Tools sub-directory below the interface directory:
Run these by double-clicking on them. A pop-up window will request the names of the input and output files.
This is all on one line, and shows the UTC timestamp that came with the data, both raw and translated, the timestamp translated into local time, both raw and translated, the PI Time sent to the PI Server, then the group number and the TransID.
For advise tags, the group number in the opcresponse.log file may not be correct for entries generated by /DB=32 or /DB=64, although the shorter entries generated by /DB=8 do correspond to the correct group number.
By looking at the log files, you can see when the interface decided to poll, when it made the call, and when the data came in. A major clue is that the flag in opcscan.log should never be anything but zero -- if it’s not zero, then the last call made to the server has not returned by the time the interface decided it was time for another poll. This should never happen so if you see a 1 in that flag, you’ll need to talk to your server vendor and have them call OSIsoft.
An alternative method to determine whether the OPC server is not responding to the Refresh calls made by the OPC Interface is to check the pipc.log file for the following message:
The OPC server did not respond to the last Refresh call for scanclass 2, and has not has not responded to the previous 100 Refresh call(s).
This message indicates that the OPC server failed to respond to a Refresh call, and typically results when the OPC server cannot keep up with the update rates or has suspended operation due to a bug. Additionally, the above message will be repeated for each additional 100 Refresh calls that do receive responses from the OPC server for each scan class. If these messages appear in your pipc.log, you should immediately contact your OPC server vendor as data loss may be occurring.
Another common use for these files is to show the timestamp returned from the OPC Server. Remember, this is UTC time, which the interface translates into local clock time and then adjusts for PI. UTC time is based in 1600, so if you see a date around 1600 you can be sure the server is not sending valid timestamps and you may want to use /TS=N to have the interface create timestamps when it gets the data.