Hi
I'm testing Loggernet for Linux (LoggerNet 4.2.1 on Ubuntu 14.04.1) as we'd like to switch to Linux. I have it running since about 3 months with only 1 Logger configured. The logger has a GPRS modem and therefore is connected via IP to collect its data, collecting data every 30 minutes. Several times (3), the data collection stucked and the only way I found to get it working again was a restart of LoggerNet. Stucked data collection is no option in our operative network.
In the logs I found the message "Should get off line because of a parent request". So it seems to me that the process which collects data is kind of stuck.
So far I can tell that Loggernet for Linux is less stable than the Windows version. I never run into a similar issue on Windows so far.
Any help or feedback is much appreciated.
Kind regards,
Marcel
Extract of State$.log File:
"2015-01-27 23:40:00.000","SCB2","Dev::sesBegin","0xf6068258"
"2015-01-27 23:40:00.001","SCB2","Dev::cmdAdd","Classic::CmdA","2"
"2015-01-27 23:40:00.001","41798749388.wsl.ch","Dev::reqDevice","Requesting device: SCB2"
"2015-01-27 23:40:00.001","41798749388.wsl.ch","Dev::onNextCommand","Opening"
"2015-01-27 23:40:03.849","41798749388.wsl.ch","Dev::sesBegin","0xf608ba18"
"2015-01-27 23:40:03.849","41798749388.wsl.ch","Dev","Going on-line"
"2015-01-27 23:40:03.849","SCB2","Dev::reqDevResp","41798749388.wsl.ch","SCB2","success"
"2015-01-27 23:40:03.850","SCB2","Dev::sesBegin","0xf6059738"
"2015-01-27 23:40:03.850","SCB2","Dev","Going on-line"
"2015-01-27 23:40:03.850","SCB2","Dev::onNextCommand","Executing command","Classic::CmdA","2"
"2015-01-27 23:40:12.831","SCB2","Dev::cmdAdd","Classic::CommandG","2"
"2015-01-27 23:40:12.831","SCB2","Dev::cmdFinished","Classic::CmdA"
"2015-01-27 23:40:12.831","SCB2","Dev::onNextCommand","Executing command","Classic::CommandG","2"
"2015-01-27 23:40:14.435","SCB2","Dev::cmdAdd","Classic::CommandF","2"
"2015-01-27 23:40:14.435","SCB2","Dev::cmdFinished","Classic::CommandG"
"2015-01-27 23:40:14.436","SCB2","Dev::onNextCommand","Executing command","Classic::CommandF","2"
"2015-01-27 23:40:16.930","SCB2","Dev::cmdAdd","Classic::CommandF","2"
"2015-01-27 23:40:16.930","SCB2","Dev::cmdFinished","Classic::CommandF"
"2015-01-27 23:40:16.930","SCB2","Dev::onNextCommand","Executing command","Classic::CommandF","2"
"2015-01-27 23:40:19.513","SCB2","Dev::cmdFinished","Classic::CommandF"
"2015-01-27 23:40:19.513","SCB2","DevHelpers::HangupDelaySession","Hangup delay: 10"
"2015-01-27 23:40:19.513","SCB2","Dev::sesEnd","0xf6068258"
"2015-01-27 23:40:19.516","SCB2","DevHelpers::HangupDelaySession","post completion"
"2015-01-27 23:40:19.516","SCB2","Dev::sesEnd","0xf6059738"
"2015-01-27 23:40:19.516","SCB2","Dev","Hangup delay complete received, no sessions left"
"2015-01-27 23:40:19.516","SCB2","Dev::onNextCommand","Ending"
"2015-01-27 23:40:20.008","","LgrNet::saveNetMap","starting save process"
"2015-01-27 23:40:20.009","","LgrNet::saveNetMap","posting rewrite command"
"2015-01-27 23:40:20.012","","LgrNet::saveNetMap","save complete"
"2015-01-27 23:40:24.489","41798749388.wsl.ch","Dev::relDevice","SCB2"
"2015-01-27 23:40:24.489","SCB2","Dev::cmdFinished","Classic::CmdEnd"
"2015-01-27 23:40:24.489","SCB2","Dev::sesEnd","0"
"2015-01-27 23:40:24.489","SCB2","Dev::goingOffLine","Reset off-line counter"
"2015-01-27 23:40:24.489","41798749388.wsl.ch","Dev","undialing complete"
"2015-01-27 23:40:24.489","41798749388.wsl.ch","DevHelpers::HangupDelaySession","Hangup delay: 10"
"2015-01-27 23:40:24.496","41798749388.wsl.ch","DevHelpers::HangupDelaySession","post completion"
"2015-01-27 23:40:24.496","41798749388.wsl.ch","Dev::sesEnd","0xf608ba18"
"2015-01-27 23:40:24.496","41798749388.wsl.ch","Dev","Hangup delay complete received, no sessions left"
"2015-01-27 23:40:24.496","41798749388.wsl.ch","Dev::onNextCommand","Ending"
"2015-01-27 23:40:24.589","41798749388.wsl.ch","Dev::cmdFinished","Comm::Root::end_command_type"
"2015-01-27 23:40:24.589","41798749388.wsl.ch","Dev::sesEnd","0"
"2015-01-27 23:40:24.589","41798749388.wsl.ch","Dev::goingOffLine","Reset off-line counter"
"2015-01-27 23:40:24.589","41798749388.wsl.ch","Root::goingOffLine","Callback delay armed"
"2015-01-27 23:40:25.588","41798749388.wsl.ch","Comm::Root::onOneShotFired","Callback delay"
"2015-01-28 00:10:00.001","SCB2","Dev::sesBegin","0xf603f168"
"2015-01-28 00:10:00.001","SCB2","Dev::cmdAdd","Classic::CmdA","2"
"2015-01-28 00:10:00.001","41798749388.wsl.ch","Dev::reqDevice","Requesting device: SCB2"
"2015-01-28 00:10:00.001","41798749388.wsl.ch","Dev::onNextCommand","Opening"
"2015-01-28 00:12:07.241","41798749388.wsl.ch","Dev::sesBegin","0xf60c1428"
"2015-01-28 00:12:07.241","41798749388.wsl.ch","Dev","Going on-line"
"2015-01-28 00:12:07.241","SCB2","Dev::reqDevResp","41798749388.wsl.ch","SCB2","success"
"2015-01-28 00:12:07.241","SCB2","Dev::sesBegin","0xf60be238"
"2015-01-28 00:12:07.241","SCB2","Dev","Going on-line"
"2015-01-28 00:12:07.241","SCB2","Dev::onNextCommand","Executing command","Classic::CmdA","2"
"2015-01-28 00:13:07.948","SCB2","Dev::sesEnd","0xf60be238"
"2015-01-28 00:13:07.948","41798749388.wsl.ch","Dev::sesEnd","0xf60c1428"
"2015-01-28 00:13:07.949","SCB2","Dev::cmdFinished","Classic::CmdA"
"2015-01-28 00:13:07.949","SCB2","Dev::sesEnd","0xf603f168"
"2015-01-28 00:13:07.949","SCB2","Dev::shouldGetOffLine","Should get off line because of a parent request"
"2015-01-28 00:13:07.949","SCB2","Dev::onNextCommand","Ending"
"2015-01-28 00:13:07.949","41798749388.wsl.ch","Dev::relDevice","SCB2"
"2015-01-28 00:13:07.949","SCB2","Dev::goingOffLine","Reset off-line counter"
"2015-01-28 00:13:07.949","41798749388.wsl.ch","Dev","undialing complete"
"2015-01-28 00:13:07.949","41798749388.wsl.ch","Dev::on_undial_complete","there is no hangup delay session"
"2015-01-28 00:13:07.949","41798749388.wsl.ch","Dev::shouldGetOffLine","Should get off line because of a parent request"
"2015-01-28 00:13:07.949","41798749388.wsl.ch","Dev::onNextCommand","Ending"
"2015-01-28 00:13:07.949","41798749388.wsl.ch","Dev::cmdFinished","Comm::Root::end_command_type"
"2015-01-28 00:13:07.949","41798749388.wsl.ch","Dev::sesEnd","0"
"2015-01-28 00:13:07.949","41798749388.wsl.ch","Dev::goingOffLine","Reset off-line counter"
"2015-01-28 00:13:07.949","41798749388.wsl.ch","Root::goingOffLine","Callback delay armed"
"2015-01-28 00:13:08.948","41798749388.wsl.ch","Comm::Root::onOneShotFired","Callback delay"
"2015-01-28 00:13:10.008","","LgrNet::saveNetMap","starting save process"
"2015-01-28 00:13:10.009","","LgrNet::saveNetMap","posting rewrite command"
"2015-01-28 00:13:10.010","","LgrNet::saveNetMap","save complete"
The state log is probably not the log to focus on. I would start with a review of the Trans.log. The information there will likely prove more useful.
Dana W.
As Dana notes, the object state log (state*.log files) contains information that is useful for troubleshooting internal issues and that may or may not be relevant to a particular problem. The transaction (Tran*.log) and communication (Comm*.log) files are generally more useful.
In your particular case, I suspect that communication with the datalogger is failing and LoggerNet has moved the station into primary or secondary retries. By default, the secondary retry interval is one day and this can indeed convey the impression that the station is "stuck". The status monitor and the troubleshooter clients are both excellent tools for helping to identify these kinds of problems.
Thank you for your answers. Unfortunately, I don't have the logs anymore. I lost them when I reinstalled the package. However, I disabled the secondary retry and will post again in case I'll run into the same problem.
Thanks,
Marcel
Hey
It happened again. I now configured 5 loggers on my LoggerNet for Linux. The data collection of one logger (ENET_1MAE2) is stucked. The other loggers get collected just fine.
Schedule configuration:
Basetime: 00:04:00
Collection interval: 30 min
Primary retry interval: 2 min
Number of primary retries: 2
Secondary interval: disabled.
Last data I got is from 2015-02-16 11:30:00. Our operative Windows LoggerNet is polling the same logger without any problems.
Extract of the state logs see below. I can provide full logs if required.
Kind regards,
Marcel
"2015-02-16 10:34:00.005","ENET_1MAE2","188","Next time to poll","2015-02-16 11:04:00"
"2015-02-16 10:34:00.006","ENET_1MAE2","96","Scheduled poll started"
"2015-02-16 10:34:00.006","ENET_1MAE2","92","Collect area poll started","ENET_Snow"
"2015-02-16 10:34:08.354","ENET_1MAE2","41","Records received","ENET_Snow","7592","7592","polling"
"2015-02-16 10:34:08.356","ENET_1MAE2","144","data file opened","ENET_Snow","/home/dataflow/Spools/Dispatcher/1MAE2.dat"
"2015-02-16 10:34:08.358","ENET_1MAE2","145","data file closed","ENET_Snow","/home/dataflow/Spools/Dispatcher/1MAE2.dat"
"2015-02-16 10:34:08.358","ENET_1MAE2","94","Collect area poll complete","ENET_Snow","15","15"
"2015-02-16 10:34:08.358","ENET_1MAE2","97","Scheduled polling complete"
"2015-02-16 10:34:08.358","ENET_1MAE2","188","Next time to poll","2015-02-16 11:04:00"
"2015-02-16 11:04:00.005","ENET_1MAE2","188","Next time to poll","2015-02-16 11:34:00"
"2015-02-16 11:04:00.006","ENET_1MAE2","96","Scheduled poll started"
"2015-02-16 11:04:00.006","ENET_1MAE2","92","Collect area poll started","ENET_Snow"
"2015-02-16 11:06:42.326","ENET_1MAE2","95","Collect area poll failed","ENET_Snow","0","0"
"2015-02-16 11:06:42.327","ENET_1MAE2","188","Next time to poll","2015-02-16 11:04:00"
"2015-02-16 11:06:42.327","ENET_1MAE2","98","Scheduled polling failed"
"2015-02-16 11:06:42.327","ENET_1MAE2","59","Collection schedule: primary retry"
"2015-02-16 11:06:42.327","ENET_1MAE2","188","Next time to poll","2015-02-16 11:08:42.327429"
"2015-02-16 11:06:42.327","ENET_1MAE2","188","Next time to poll","2015-02-16 11:08:42.327429"
"2015-02-16 11:08:42.333","ENET_1MAE2","188","Next time to poll","2015-02-16 11:10:42.327429"
"2015-02-16 11:08:42.333","ENET_1MAE2","96","Scheduled poll started"
"2015-02-16 11:08:42.333","ENET_1MAE2","92","Collect area poll started","ENET_Snow"
"2015-02-16 11:10:42.333","ENET_1MAE2","188","Next time to poll","2015-02-16 11:12:42.327429"
"2015-02-16 11:11:24.566","ENET_1MAE2","95","Collect area poll failed","ENET_Snow","0","0"
"2015-02-16 11:11:24.566","ENET_1MAE2","98","Scheduled polling failed"
"2015-02-16 11:11:24.567","ENET_1MAE2","62","Primary retry collection attempt failed"
"2015-02-16 11:11:24.567","ENET_1MAE2","188","Next time to poll","2015-02-16 11:12:42.327429"
"2015-02-16 11:12:42.333","ENET_1MAE2","188","Next time to poll","2015-02-16 11:14:42.327429"
"2015-02-16 11:12:42.333","ENET_1MAE2","96","Scheduled poll started"
"2015-02-16 11:12:42.333","ENET_1MAE2","92","Collect area poll started","ENET_Snow"
"2015-02-16 11:14:42.333","ENET_1MAE2","188","Next time to poll","2015-02-16 11:16:42.327429"
"2015-02-16 11:15:24.566","ENET_1MAE2","95","Collect area poll failed","ENET_Snow","0","0"
"2015-02-16 11:15:24.566","ENET_1MAE2","98","Scheduled polling failed"
"2015-02-16 11:15:24.566","ENET_1MAE2","62","Primary retry collection attempt failed"
"2015-02-16 11:15:24.567","ENET_1MAE2","130","Last primary retry failed","1"
"2015-02-16 11:15:24.567","ENET_1MAE2","58","Collection schedule: normal"
"2015-02-16 11:15:24.567","ENET_1MAE2","188","Next time to poll","2015-02-16 11:34:00"
"2015-02-16 11:15:24.567","ENET_1MAE2","188","Next time to poll","2015-02-16 11:34:00"
"2015-02-16 11:34:00.001","ENET_1MAE2","188","Next time to poll","2015-02-16 12:04:00"
"2015-02-16 11:34:00.001","ENET_1MAE2","96","Scheduled poll started"
"2015-02-16 11:34:00.001","ENET_1MAE2","92","Collect area poll started","ENET_Snow"
"2015-02-16 11:34:19.394","ENET_1MAE2","188","Next time to poll","2015-02-16 11:34:00"
"2015-02-16 11:34:19.406","ENET_1MAE2","188","Next time to poll","2015-02-16 12:04:00"
"2015-02-16 11:34:20.332","ENET_1MAE2","41","Records received","ENET_Snow","7594","7594","polling"
"2015-02-16 11:34:20.332","ENET_1MAE2","20","Hole detected","ENET_Snow","7593","7593"
"2015-02-16 11:34:21.092","ENET_1MAE2","41","Records received","ENET_Snow","7593","7593","polling"
"2015-02-16 11:34:21.093","ENET_1MAE2","144","data file opened","ENET_Snow","/home/dataflow/Spools/Dispatcher/1MAE2.dat"
"2015-02-16 11:34:21.093","ENET_1MAE2","21","Hole collected","ENET_Snow","7593","7593"
"2015-02-16 11:34:21.094","ENET_1MAE2","145","data file closed","ENET_Snow","/home/dataflow/Spools/Dispatcher/1MAE2.dat"
"2015-02-16 11:34:21.095","ENET_1MAE2","94","Collect area poll complete","ENET_Snow","30","30"
"2015-02-16 11:34:21.095","ENET_1MAE2","97","Scheduled polling complete"
"2015-02-16 11:34:21.095","ENET_1MAE2","188","Next time to poll","2015-02-16 12:04:00"
"2015-02-16 12:04:00.006","ENET_1MAE2","188","Next time to poll","2015-02-16 12:34:00"
"2015-02-16 12:04:00.006","ENET_1MAE2","96","Scheduled poll started"
"2015-02-16 12:04:00.006","ENET_1MAE2","92","Collect area poll started","ENET_Snow"
"2015-02-16 12:06:42.196","ENET_1MAE2","95","Collect area poll failed","ENET_Snow","0","0"
"2015-02-16 12:06:42.197","ENET_1MAE2","188","Next time to poll","2015-02-16 12:04:00"
"2015-02-16 12:06:42.197","ENET_1MAE2","98","Scheduled polling failed"
"2015-02-16 12:06:42.197","ENET_1MAE2","59","Collection schedule: primary retry"
"2015-02-16 12:06:42.197","ENET_1MAE2","188","Next time to poll","2015-02-16 12:08:42.197439"
"2015-02-16 12:06:42.197","ENET_1MAE2","188","Next time to poll","2015-02-16 12:08:42.197439"
"2015-02-16 12:08:42.205","ENET_1MAE2","188","Next time to poll","2015-02-16 12:10:42.197439"
"2015-02-16 12:08:42.205","ENET_1MAE2","96","Scheduled poll started"
"2015-02-16 12:08:42.205","ENET_1MAE2","92","Collect area poll started","ENET_Snow"
"2015-02-16 12:10:42.205","ENET_1MAE2","188","Next time to poll","2015-02-16 12:12:42.197439"
"2015-02-16 12:11:24.436","ENET_1MAE2","95","Collect area poll failed","ENET_Snow","0","0"
"2015-02-16 12:11:24.436","ENET_1MAE2","98","Scheduled polling failed"
"2015-02-16 12:11:24.437","ENET_1MAE2","62","Primary retry collection attempt failed"
"2015-02-16 12:11:24.437","ENET_1MAE2","188","Next time to poll","2015-02-16 12:12:42.197439"
"2015-02-16 12:12:42.205","ENET_1MAE2","188","Next time to poll","2015-02-16 12:14:42.197439"
"2015-02-16 12:12:42.205","ENET_1MAE2","96","Scheduled poll started"
"2015-02-16 12:12:42.205","ENET_1MAE2","92","Collect area poll started","ENET_Snow"
"2015-02-16 12:14:42.205","ENET_1MAE2","188","Next time to poll","2015-02-16 12:16:42.197439"
"2015-02-16 12:16:42.205","ENET_1MAE2","188","Next time to poll","2015-02-16 12:18:42.197439"
"2015-02-16 12:18:42.205","ENET_1MAE2","188","Next time to poll","2015-02-16 12:20:42.197439"
"2015-02-16 12:20:42.205","ENET_1MAE2","188","Next time to poll","2015-02-16 12:22:42.197439"
"2015-02-16 12:22:42.205","ENET_1MAE2","188","Next time to poll","2015-02-16 12:24:42.197439"
"2015-02-16 12:24:42.205","ENET_1MAE2","188","Next time to poll","2015-02-16 12:26:42.197439"
"2015-02-16 12:26:42.205","ENET_1MAE2","188","Next time to poll","2015-02-16 12:28:42.197439"
"2015-02-16 12:28:42.205","ENET_1MAE2","188","Next time to poll","2015-02-16 12:30:42.197439"
"2015-02-16 12:30:42.205","ENET_1MAE2","188","Next time to poll","2015-02-16 12:32:42.197439"
"2015-02-16 12:32:42.205","ENET_1MAE2","188","Next time to poll","2015-02-16 12:34:42.197439"
"2015-02-16 12:34:42.205","ENET_1MAE2","188","Next time to poll","2015-02-16 12:36:42.197439"
"2015-02-16 12:36:42.205","ENET_1MAE2","188","Next time to poll","2015-02-16 12:38:42.197439"
"2015-02-16 12:38:42.205","ENET_1MAE2","188","Next time to poll","2015-02-16 12:40:42.197439"
"2015-02-16 12:40:42.205","ENET_1MAE2","188","Next time to poll","2015-02-16 12:42:42.197439"
"2015-02-16 12:42:42.205","ENET_1MAE2","188","Next time to poll","2015-02-16 12:44:42.197439"
"2015-02-16 12:44:42.205","ENET_1MAE2","188","Next time to poll","2015-02-16 12:46:42.197439"
"2015-02-16 12:46:42.205","ENET_1MAE2","188","Next time to poll","2015-02-16 12:48:42.197439"
"2015-02-16 12:48:42.205","ENET_1MAE2","188","Next time to poll","2015-02-16 12:50:42.197439"
"2015-02-16 12:50:42.205","ENET_1MAE2","188","Next time to poll","2015-02-16 12:52:42.197439"
"2015-02-16 12:52:42.205","ENET_1MAE2","188","Next time to poll","2015-02-16 12:54:42.197439"
"2015-02-16 12:54:42.205","ENET_1MAE2","188","Next time to poll","2015-02-16 12:56:42.197439"
"2015-02-16 12:56:42.205","ENET_1MAE2","188","Next time to poll","2015-02-16 12:58:42.197439"
"2015-02-16 12:58:42.205","ENET_1MAE2","188","Next time to poll","2015-02-16 13:00:42.197439"
"2015-02-16 13:00:42.205","ENET_1MAE2","188","Next time to poll","2015-02-16 13:02:42.197439"
"2015-02-16 13:02:42.205","ENET_1MAE2","188","Next time to poll","2015-02-16 13:04:42.197439"
"2015-02-16 13:04:42.205","ENET_1MAE2","188","Next time to poll","2015-02-16 13:06:42.197439"
"2015-02-16 13:06:42.205","ENET_1MAE2","188","Next time to poll","2015-02-16 13:08:42.197439"
"2015-02-16 13:08:42.205","ENET_1MAE2","188","Next time to poll","2015-02-16 13:10:42.197439"
"2015-02-16 13:10:42.205","ENET_1MAE2","188","Next time to poll","2015-02-16 13:12:42.197439"
"2015-02-16 13:12:42.205","ENET_1MAE2","188","Next time to poll","2015-02-16 13:14:42.197439"
"2015-02-16 13:14:42.205","ENET_1MAE2","188","Next time to poll","2015-02-16 13:16:42.197439"
"2015-02-16 13:16:42.205","ENET_1MAE2","188","Next time to poll","2015-02-16 13:18:42.197439"
"2015-02-16 13:18:42.205","ENET_1MAE2","188","Next time to poll","2015-02-16 13:20:42.197439"
"2015-02-16 13:20:42.205","ENET_1MAE2","188","Next time to poll","2015-02-16 13:22:42.197439"
"2015-02-16 13:22:42.205","ENET_1MAE2","188","Next time to poll","2015-02-16 13:24:42.197439"
"2015-02-16 13:24:42.205","ENET_1MAE2","188","Next time to poll","2015-02-16 13:26:42.197439"
"2015-02-16 13:26:42.205","ENET_1MAE2","188","Next time to poll","2015-02-16 13:28:42.197439"
"2015-02-16 13:28:42.205","ENET_1MAE2","188","Next time to poll","2015-02-16 13:30:42.197439"
"2015-02-16 13:30:42.205","ENET_1MAE2","188","Next time to poll","2015-02-16 13:32:42.197439"
"2015-02-16 13:32:42.205","ENET_1MAE2","188","Next time to poll","2015-02-16 13:34:42.197439"