I’ve made a hot fix to the GitHub file [tt]openLuup/scheduler.lua[/tt] which provides extended traceback of errors. This should help isolating this, and any other, future problems.
Can you generate that error again and see what the log says now?
Will do…
[quote=“akbooer, post:41, topic:189395”]I’ve made a hot fix to the GitHub file [tt]openLuup/scheduler.lua[/tt] which provides extended traceback of errors. This should help isolating this, and any other, future problems.
Can you generate that error again and see what the log says now?[/quote]
Loaded file from Git, however it seems displeased.
root@Cobalt:/vera/cmh-ludl# ./openLuup_reload
lua: ./openLuup/scheduler.lua:358: attempt to index global 'schedule' (a nil value)
stack traceback:
./openLuup/scheduler.lua:358: in function 'socket_callbacks'
./openLuup/scheduler.lua:421: in function 'start'
openLuup/init.lua:201: in main chunk
[C]: ?
root@Cobalt:/vera/cmh-ludl#-rw-r--r-- 1 root root 4090 Nov 13 03:05 chdev.lua
-rw-r--r-- 1 root root 22563 Nov 13 03:05 devices.lua
-rw-r--r-- 1 root root 8044 Nov 13 03:05 gateway.lua
-rw-r--r-- 1 root root 7928 Nov 13 03:05 init.lua
-rw-r--r-- 1 root root 7806 Nov 13 03:05 io.lua
-rw-r--r-- 1 root root 11000 Nov 13 03:05 json.lua
-rw-r--r-- 1 root root 9766 Nov 13 03:05 loader.lua
-rw-r--r-- 1 root root 8988 Nov 13 03:05 logs.lua
-rw-r--r-- 1 root root 22315 Nov 13 03:05 luup.lua
-rw-r--r-- 1 root root 8100 Nov 13 03:05 plugins.lua
-rw-r--r-- 1 root root 22026 Nov 13 03:05 requests.lua
-rw-r--r-- 1 root root 2964 Nov 13 03:05 rooms.lua
-rw-r--r-- 1 root root 7086 Nov 13 03:05 scenes.lua
-rw-r--r-- 1 root root 15077 Nov 13 03:05 scheduler.lua
-rw-r--r-- 1 root root 14514 Nov 13 03:05 server.lua
-rw-r--r-- 1 root root 13746 Nov 13 03:05 timers.lua
-rw-r--r-- 1 root root 5602 Nov 13 03:05 userdata.lua
-rw-r--r-- 1 root root 4079 Nov 13 03:05 xml.luaShameful performance from me… there was a typo in an error branch that the unit tests can’t easily exercise… but it does mean that your code was creating some sort of error! Now we should be able to see exactly where.
It’s updated in GitHib.
Sorry, as usual, for the inconvenience.
No inconvenience whatsoever. Just hoping this issue can be isolated. Will load but won’t be able to test until tonight.
Thanks for your help…
Shameful performance from me… there was a typo in an error branch that the unit tests can’t easily exercise… but it does mean that your code was creating some sort of error! Now we should be able to see exactly where.
It’s updated in GitHib.
Sorry, as usual, for the inconvenience.[/quote]
I wish i had good news…
Without new scheduler.lua
2015-11-13 21:30:09.617 :: openLuup STARTUP ::
2015-11-13 21:30:09.617 openLuup.init:: version 2015.11.01 @akbooer
2015-11-13 21:30:09.628 openLuup.scheduler:: version 2015.11.03 @akbooer
2015-11-13 21:30:09.629 openLuup.server:: version 2015.11.01 @akbooer
2015-11-13 21:30:09.631 openLuup.plugins:: version 2015.11.06 @akbooer
2015-11-13 21:30:09.633 openLuup.scenes:: version 2015.10.26 @akbooer
2015-11-13 21:30:09.634 openLuup.chdev:: version 2015.11.01 @akbooer
2015-11-13 21:30:09.635 openLuup.io:: version 2015.10.15 @akbooer
2015-11-13 21:30:09.635 openLuup.luup:: version 2015.11.03 @akbooer
2015-11-13 21:30:09.639 openLuup.rooms:: version 2015.10.15 @akbooer
2015-11-13 21:30:09.639 openLuup.requests:: version 2015.10.30 @akbooer
2015-11-13 21:30:09.639 luup.create_device:: [1] urn:schemas-micasaverde-com:device:ZWaveNetwork:1 / no-implementation-file
2015-11-13 21:30:09.640 luup.create_device:: [2] urn:schemas-micasaverde-com:device:SceneController:1 / no-implementation-file
2015-11-13 21:30:09.640 openLuup.init:: loading configuration user_data.json
2015-11-13 21:30:09.640 openLuup.init:: loading user_data json...
2015-11-13 21:30:09.642 openLuup.init:: loading rooms...
2015-11-13 21:30:09.642 openLuup.init:: room#1 'Upstairs'
2015-11-13 21:30:09.643 openLuup.init:: room#2 'Downstairs'
2015-11-13 21:30:09.643 openLuup.init:: ...room loading completed
2015-11-13 21:30:09.643 openLuup.init:: loading devices...
2015-11-13 21:30:09.643 openLuup.init:: [1] 'ZWave', urn:schemas-micasaverde-com:device:ZWaveNetwork:1
2015-11-13 21:30:09.643 openLuup.init:: [2] '_SceneController', urn:schemas-micasaverde-com:device:SceneController:1
2015-11-13 21:30:09.643 openLuup.init:: [3] 'ALTUI', urn:schemas-upnp-org:device:altui:1
2015-11-13 21:30:09.666 openLuup.init:: loading scenes...
2015-11-13 21:30:09.666 openLuup.init:: number of scenes = 0
2015-11-13 21:30:09.667 openLuup.init:: ...scene loading completed
2015-11-13 21:30:09.667 openLuup.init:: loading installed plugin info...
2015-11-13 21:30:09.667 openLuup.init:: ...user_data loading completed
2015-11-13 21:30:09.667 openLuup.init:: running _openLuup_STARTUP_
2015-11-13 21:30:09.667 openLuup.init:: startup completed
2015-11-13 21:30:09.668 openLuup.server:: starting HTTP server on 10.0.4.10:3480 tcp{server}: 0x12efc38
2015-11-13 21:30:09.668 openLuup.scheduler:: starting
2015-11-13 21:30:09.668 openLuup.scheduler:3: device startup
2015-11-13 21:30:09.668 luup_log:3: ALTUI: initstatus(3) starting version: v0.96
2015-11-13 21:30:09.668 openLuup.scheduler:3: device startup completed: status=nil, msg=nil, name=nil
2015-11-13 21:30:10.671 luup_log:3: ALTUI: startupDeferred, called on behalf of device:3
2015-11-13 21:30:10.671 luup.variable_set:3: 3.urn:upnp-org:serviceId:altui1.Debug was: EMPTY now: 0 #hooks:0
2015-11-13 21:30:10.671 luup.variable_set:3: 3.urn:upnp-org:serviceId:altui1.Version was: EMPTY now: v0.96 #hooks:0
2015-11-13 21:30:10.672 luup.variable_set:3: 3.urn:upnp-org:serviceId:altui1.Present was: EMPTY now: 0 #hooks:0
2015-11-13 21:30:10.672 luup.variable_set:3: 3.urn:upnp-org:serviceId:altui1.RemoteAccess was: EMPTY now: https://vera-ui.strongcubedfitness.com/Veralogin.php #hooks:0
2015-11-13 21:30:10.672 luup.variable_set:3: 3.urn:upnp-org:serviceId:altui1.LocalHome was: EMPTY now: /port_3480/data_request?id=lr_ALTUI_Handler&command=home #hooks:0
2015-11-13 21:30:10.673 luup.variable_set:3: 3.urn:upnp-org:serviceId:altui1.ThemeCSS was: EMPTY now: #hooks:0
2015-11-13 21:30:10.673 luup.variable_set:3: 3.urn:upnp-org:serviceId:altui1.ExtraController was: EMPTY now: #hooks:0
2015-11-13 21:30:10.673 luup.variable_set:3: 3.urn:upnp-org:serviceId:altui1.ServerOptions was: EMPTY now: #hooks:0
2015-11-13 21:30:10.674 luup.variable_set:3: 3.urn:upnp-org:serviceId:altui1.LocalCDN was: EMPTY now: #hooks:0
2015-11-13 21:30:10.674 luup.variable_set:3: 3.urn:upnp-org:serviceId:altui1.LocalBootstrap was: EMPTY now: #hooks:0
2015-11-13 21:30:10.676 luup.variable_set:3: 3.urn:upnp-org:serviceId:altui1.PluginConfig was: EMPTY now: {"urn:schemas-micasaverde-com:device:PowerMeter:1":{"DeviceDrawFunc":"ALTUI_PluginDisplays.drawPowerMeter","ScriptFile":"J_ALTUI_plugins.js"},"urn:schemas-futzle-com:device:CombinationSwitch:1":{"DeviceDrawFunc":"ALTUI_PluginDisplays.drawCombinationSwitch","ScriptFile":"J_ALTUI_plugins.js"},"urn:richardgreen:device:VeraAlert:1":{"DeviceDrawFunc":"ALTUI_PluginDisplays.drawVeraAlerts","ScriptFile":"J_ALTUI_plugins.js"},"urn:schemas-futzle-com:device:UPnPProxy:1":{"DeviceDrawFunc":"ALTUI_PluginDisplays.drawPnPProxy","ScriptFile":"J_ALTUI_plugins.js"},"urn:schemas-upnp-org:device:Heater:1":{"DeviceDrawFunc":"ALTUI_PluginDisplays.drawHeater","ScriptFile":"J_ALTUI_plugins.js"},"urn:schemas-upnp-org:device:HVAC_ZoneThermostat:1":{"DeviceDrawFunc":"ALTUI_PluginDisplays.drawZoneThermostat","ScriptFile":"J_ALTUI_plugins.js"},"urn:schemas-micasaverde-com:device:DoorLock:1":{"DeviceDrawFunc":"ALTUI_PluginDisplays.drawDoorLock","ScriptFile":"J_ALTUI_plugins.js"},"urn:schemas-micasaverde-com:device:DoorSensor:1":{"DeviceDrawFunc":"ALTUI_PluginDisplays.drawDoorSensor","ScriptFile":"J_ALTUI_plugins.js"},"urn:schemas-rts-services-com:device:ProgramLogicTS:1":{"DeviceDrawFunc":"ALTUI_PluginDisplays.drawProgLogicTimerSwitch","ScriptFile":"J_ALTUI_plugins.js"},"urn:schemas-upnp-org:device:RGBController:1":{"DeviceDrawFunc":"ALTUI_PluginDisplays.drawBinaryLight","ScriptFile":"J_ALTUI_plugins.js"},"urn:schemas-micasaverde-com:device:PowerMeter:2":{"DeviceDrawFunc":"ALTUI_PluginDisplays.drawPowerMeter","ScriptFile":"J_ALTUI_plugins.js"},"urn:schemas-upnp-org:device:IPX800:1":{"DeviceDrawFunc":"ALTUI_IPhoneLocator.drawIPX","ScriptFile":"J_ALTUI_iphone.js"},"urn:schemas-arduino-cc:device:arduino:1":{"DeviceDrawFunc":"ALTUI_PluginDisplays.drawMySensors","ScriptFile":"J_ALTUI_plugins.js"},"urn:schemas-micasaverde-com:device:Sonos:1":{"DeviceDrawFunc":"ALTUI_PluginDisplays.drawSonos","ScriptFile":"J_ALTUI_plugins.js"},"urn:schemas-dcineco-com:device:MSwitch:1":{"DeviceDrawFunc":"ALTUI_PluginDisplays.drawMultiswitch","ScriptFile":"J_ALTUI_plugins.js"},"urn:schemas-upnp-org:device:DigitalSecurityCamera:2":{"DeviceDrawFunc":"ALTUI_PluginDisplays.drawCamera","ScriptFile":"J_ALTUI_plugins.js"},"urn:schemas-micasaverde-com:device:MotionSensor:1":{"DeviceDrawFunc":"ALTUI_PluginDisplays.drawMotion","ScriptFile":"J_ALTUI_plugins.js"},"urn:schemas-micasaverde-com:device:TempLeakSensor:1":{"DeviceDrawFunc":"ALTUI_PluginDisplays.drawTempLeak","ScriptFile":"J_ALTUI_plugins.js"},"urn:schemas-rts-services-com:device:ProgramLogicEG:1":{"DeviceDrawFunc":"ALTUI_PluginDisplays.drawPLEG","ScriptFile":"J_ALTUI_plugins.js"},"urn:schemas-cd-jackson-com:device:SystemMonitor:1":{"DeviceDrawFunc":"ALTUI_PluginDisplays.drawSysMonitor","ScriptFile":"J_ALTUI_plugins.js"},"urn:schemas-rts-services-com:device:DayTime:1":{"DeviceDrawFunc":"ALTUI_PluginDisplays.drawDayTime","ScriptFile":"J_ALTUI_plugins.js"},"urn:schemas-upnp-org:device:VSwitch:1":{"DeviceDrawFunc":"ALTUI_PluginDisplays.drawVswitch","ScriptFile":"J_ALTUI_plugins.js"},"urn:demo-micasaverde-com:device:weather:1":{"DeviceIconFunc":"ALTUI_PluginDisplays.drawWeatherIcon","DeviceDrawFunc":"ALTUI_PluginDisplays.drawWeather","ScriptFile":"J_ALTUI_plugins.js"},"urn:schemas-upnp-org:device:IPhoneLocator:1":{"StyleFunc":"ALTUI_IPhoneLocator.getStyle","DeviceDrawFunc":"ALTUI_IPhoneLocator.drawIPhone","ScriptFile":"J_ALTUI_iphone.js"},"urn:schemas-utz-com:device:GCal:1":{"DeviceDrawFunc":"ALTUI_PluginDisplays.drawGCal","ScriptFile":"J_ALTUI_plugins.js"},"urn:schemas-upnp-org:device:VContainer:1":{"DeviceDrawFunc":"ALTUI_PluginDisplays.drawMultiString","ScriptFile":"J_ALTUI_plugins.js"},"urn:schemas-upnp-org:device:altui:1":{"DeviceDrawFunc":"ALTUI_IPhoneLocator.drawAltUI","ScriptFile":"J_ALTUI_iphone.js"},"urn:schemas-micasaverde-com:device:HumiditySensor:1":{"DeviceDrawFunc":"ALTUI_PluginDisplays.drawHumidity","ScriptFile":"J_ALTUI_plugins.js"},"urn:schemas-micasaverde-com:device:SmokeSensor:1":{"DeviceDrawFunc":"ALTUI_PluginDisplays.drawSmoke","ScriptFile":"J_ALTUI_plugins.js"},"urn:schemas-a-lurker-com:device:InfoViewer:1":{"DeviceDrawFunc":"ALTUI_PluginDisplays.drawInfoViewer","ScriptFile":"J_ALTUI_plugins.js"},"urn:schemas-cd-jackson-com:device:DataMine:1":{"DeviceDrawFunc":"ALTUI_PluginDisplays.drawDataMine","ScriptFile":"J_ALTUI_plugins.js"},"urn:schemas-futzle-com:device:CountdownTimer:1":{"DeviceDrawFunc":"ALTUI_PluginDisplays.drawCountDown","ScriptFile":"J_ALTUI_plugins.js"},"urn:schemas-futzle-com:device:holidayvirtualswitch:1":{"DeviceDrawFunc":"ALTUI_PluginDisplays.drawVacation","ScriptFile":"J_ALTUI_plugins.js"},"urn:antor-fr:device:SamsungTVRemote:1":{"DeviceDrawFunc":"ALTUI_PluginDisplays.drawBinaryLight","ScriptFile":"J_ALTUI_plugins.js"},"urn:schemas-upnp-org:device:DimmableLight:1":{"DeviceDrawFunc":"ALTUI_PluginDisplays.drawDimmable","ScriptFile":"J_ALTUI_plugins.js"},"urn:schemas-upnp-org:device:cplus:1":{"DeviceDrawFunc":"ALTUI_IPhoneLocator.drawCanalplus","ControlPanelFunc":"ALTUI_IPhoneLocator.drawCanaplusControlPanel","ScriptFile":"J_ALTUI_iphone.js"},"urn:schemas-micasaverde-com:device:TemperatureSensor:1":{"DeviceDrawFunc":"ALTUI_PluginDisplays.drawTempSensor","ScriptFile":"J_ALTUI_plugins.js"},"urn:schemas-upnp-org:device:DigitalSecurityCamera:1":{"DeviceDrawFunc":"ALTUI_PluginDisplays.drawCamera","ScriptFile":"J_ALTUI_plugins.js"},"urn:schemas-upnp-org:device:BinaryLight:1":{"StyleFunc":"ALTUI_PluginDisplays.getStyle","DeviceDrawFunc":"ALTUI_PluginDisplays.drawBinaryLight","ScriptFile":"J_ALTUI_plugins.js"},"urn:schemas-micasaverde-com:device:LightSensor:1":{"DeviceDrawFunc":"ALTUI_PluginDisplays.drawLight","ScriptFile":"J_ALTUI_plugins.js"},"urn:schemas-micasaverde-com:device:WindowCovering:1":{"DeviceDrawFunc":"ALTUI_PluginDisplays.drawWindowCover","ScriptFile":"J_ALTUI_plugins.js"}} #hooks:0
2015-11-13 21:30:10.677 luup.variable_set:3: 3.urn:upnp-org:serviceId:altui1.Version was: v0.96 now: v0.96 #hooks:0
2015-11-13 21:30:10.677 luup.variable_set:3: 3.urn:upnp-org:serviceId:altui1.VariablesToWatch was: EMPTY now: #hooks:0
2015-11-13 21:30:10.678 luup.variable_set:3: 3.urn:upnp-org:serviceId:altui1.VariablesToSend was: EMPTY now: #hooks:0
2015-11-13 21:30:10.678 luup.set_failure:3: status = 0
2015-11-13 21:30:10.678 luup.register_handler:3: global_function_name=myALTUI_Handler, request=lr_ALTUI_Handler
2015-11-13 21:30:10.685 luup.call_action:3: 0.urn:micasaverde-com:serviceId:HomeAutomationGateway1.RunLua
2015-11-13 21:30:10.686 luup.register_handler:0: global_function_name=ALTUI_LuaRunHandler, request=lr_ALTUI_LuaRunHandler
2015-11-13 21:30:10.686 luup_log:3: ALTUI: startup completed
2015-11-13 21:30:14.334 openLuup.server:: new client connection: tcp{client}: 0x1311498
2015-11-13 21:30:14.335 openLuup.server:: new client connection: tcp{client}: 0x1288738
2015-11-13 21:30:14.335 openLuup.server:: /data_request?id=lr_ALTUI_Handler&command=home tcp{client}: 0x1311498
2015-11-13 21:30:14.335 luup_log:3: ALTUI: ALTUI_Handler: request is: lr_ALTUI_Handler
2015-11-13 21:30:14.336 luup_log:3: ALTUI: ALTUI_Handler: parameters is: {"command":"home"}
2015-11-13 21:30:14.336 luup_log:3: ALTUI: ALTUI_Handler: outputformat is: null
2015-11-13 21:30:14.341 luup_log:3: ALTUI: getScriptContent(J_ALTUI_plugins.js)
2015-11-13 21:30:14.350 luup_log:3: ALTUI: getScriptContent(J_ALTUI_iphone.js)
2015-11-13 21:30:14.352 luup_log:3: ALTUI: getScriptContent(J_ALTUI_jquery.ui.touch-punch.min.js)
2015-11-13 21:30:14.353 luup_log:3: ALTUI: getScriptContent(J_ALTUI_b_blockly_compressed.js)
2015-11-13 21:30:14.362 luup_log:3: ALTUI: getScriptContent(J_ALTUI_b_blocks_compressed.js)
2015-11-13 21:30:14.365 luup_log:3: ALTUI: getScriptContent(J_ALTUI_b_en.js)
2015-11-13 21:30:14.367 luup_log:3: ALTUI: getScriptContent(J_ALTUI_b_javascript_compressed.js)
2015-11-13 21:30:14.369 luup_log:3: ALTUI: getScriptContent(J_ALTUI_b_lua_compressed.js)
2015-11-13 21:30:14.446 openLuup.server:: request completed (850820 bytes, 54 chunks, 110 ms) tcp{client}: 0x1311498
2015-11-13 21:30:14.446 openLuup.server:: new client connection: tcp{client}: 0x129ca48
2015-11-13 21:30:14.447 openLuup.server:: new client connection: tcp{client}: 0x129eaf8
2015-11-13 21:30:14.447 openLuup.server:: new client connection: tcp{client}: 0x12a0ba8
2015-11-13 21:30:14.448 openLuup.server:: new client connection: tcp{client}: 0x12f7be8
2015-11-13 21:30:14.448 openLuup.server:: /J_ALTUI_utils.js tcp{client}: 0x1288738
2015-11-13 21:30:14.454 openLuup.server:: request completed (35046 bytes, 3 chunks, 5 ms) tcp{client}: 0x1288738
2015-11-13 21:30:14.454 openLuup.server:: /J_ALTUI_upnp.js tcp{client}: 0x129ca48
2015-11-13 21:30:14.455 openLuup.server:: /J_ALTUI_multibox.js tcp{client}: 0x129eaf8
2015-11-13 21:30:14.455 openLuup.server:: /J_ALTUI_api.js tcp{client}: 0x12a0ba8
2015-11-13 21:30:14.455 openLuup.server:: /J_ALTUI_verabox.js tcp{client}: 0x12f7be8
2015-11-13 21:30:14.458 openLuup.server:: request completed (18969 bytes, 2 chunks, 3 ms) tcp{client}: 0x129ca48
2015-11-13 21:30:14.461 openLuup.server:: request completed (29722 bytes, 2 chunks, 6 ms) tcp{client}: 0x129eaf8
2015-11-13 21:30:14.466 openLuup.server:: request completed (34323 bytes, 3 chunks, 10 ms) tcp{client}: 0x12a0ba8
2015-11-13 21:30:14.470 openLuup.server:: request completed (42533 bytes, 3 chunks, 14 ms) tcp{client}: 0x12f7be8
2015-11-13 21:30:14.600 openLuup.server:: /J_ALTUI_uimgr.js tcp{client}: 0x1311498
2015-11-13 21:30:14.650 openLuup.server:: request completed (438633 bytes, 28 chunks, 50 ms) tcp{client}: 0x1311498
2015-11-13 21:30:14.805 openLuup.server:: /J_ALTUI_uimgr.js tcp{client}: 0x1311498
2015-11-13 21:30:14.839 openLuup.server:: request completed (438633 bytes, 28 chunks, 34 ms) tcp{client}: 0x1311498
2015-11-13 21:30:14.919 openLuup.server:: /luvd/D_ZWaveNetwork.xml tcp{client}: 0x1311498
2015-11-13 21:30:14.920 openLuup.HTTP.FILE:: file not found:D_ZWaveNetwork.xml
2015-11-13 21:30:14.921 openLuup.server:: request completed (0 bytes, 0 chunks, 1 ms) tcp{client}: 0x1311498
2015-11-13 21:30:14.921 openLuup.server:: /luvd/D_SceneController1.xml tcp{client}: 0x12f7be8
2015-11-13 21:30:14.921 openLuup.HTTP.FILE:: file not found:D_SceneController1.xml
2015-11-13 21:30:14.922 openLuup.server:: request completed (0 bytes, 0 chunks, 0 ms) tcp{client}: 0x12f7be8
2015-11-13 21:30:14.922 openLuup.server:: /luvd/D_ALTUI.xml tcp{client}: 0x12a0ba8
2015-11-13 21:30:14.923 openLuup.server:: request completed (1086 bytes, 1 chunks, 1 ms) tcp{client}: 0x12a0ba8
2015-11-13 21:30:14.925 openLuup.server:: /data_request?id=user_data&output_format=json&DataVersion=471809021&_=1447471809408 tcp{client}: 0x1288738
2015-11-13 21:30:14.932 openLuup.server:: request completed (15876 bytes, 1 chunks, 7 ms) tcp{client}: 0x1288738
2015-11-13 21:30:14.934 openLuup.server:: /data_request?id=variableget&DeviceNum=0&serviceId=urn:micasaverde-com:serviceId:HomeAutomationGateway1&Variable=Mode&_=1447471809412 tcp{client}: 0x1288738
2015-11-13 21:30:14.935 openLuup.server:: request completed (1 bytes, 1 chunks, 1 ms) tcp{client}: 0x1288738
2015-11-13 21:30:14.936 openLuup.server:: /J_ALTUI_b_blockly_compressed.js tcp{client}: 0x129eaf8
2015-11-13 21:30:14.984 openLuup.server:: request completed (590691 bytes, 37 chunks, 47 ms) tcp{client}: 0x129eaf8
2015-11-13 21:30:15.124 openLuup.server:: /J_ALTUI_b_blocks_compressed.js tcp{client}: 0x129eaf8
2015-11-13 21:30:15.130 openLuup.server:: request completed (67163 bytes, 5 chunks, 6 ms) tcp{client}: 0x129eaf8
2015-11-13 21:30:15.142 openLuup.server:: /J_ALTUI_b_en.js tcp{client}: 0x129eaf8
2015-11-13 21:30:15.145 openLuup.server:: request completed (28542 bytes, 2 chunks, 2 ms) tcp{client}: 0x129eaf8
2015-11-13 21:30:15.158 openLuup.server:: /J_ALTUI_b_javascript_compressed.js tcp{client}: 0x129eaf8
2015-11-13 21:30:15.161 openLuup.server:: request completed (44531 bytes, 3 chunks, 3 ms) tcp{client}: 0x129eaf8
2015-11-13 21:30:15.184 openLuup.server:: /J_ALTUI_b_lua_compressed.js tcp{client}: 0x129eaf8
2015-11-13 21:30:15.187 openLuup.server:: request completed (31571 bytes, 2 chunks, 2 ms) tcp{client}: 0x129eaf8
2015-11-13 21:30:15.287 openLuup.server:: /favicon.ico tcp{client}: 0x129eaf8
2015-11-13 21:30:15.287 openLuup.HTTP.FILE:: file not found:favicon.ico
2015-11-13 21:30:15.287 openLuup.server:: request completed (0 bytes, 0 chunks, 0 ms) tcp{client}: 0x129eaf8
2015-11-13 21:30:17.011 openLuup.server:: /data_request?id=lu_status2&output_format=json&DataVersion=1&Timeout=60&MinimumDelay=1500&_=1447471809413 tcp{client}: 0x129eaf8
2015-11-13 21:30:17.877 openLuup.server:: /data_request?id=sdata&output_format=json&_=1447471809414 tcp{client}: 0x1288738
2015-11-13 21:30:17.879 openLuup.server:: request completed (513 bytes, 1 chunks, 2 ms) tcp{client}: 0x1288738
2015-11-13 21:30:18.886 openLuup.server:: request completed (8900 bytes, 1 chunks, 1874 ms) tcp{client}: 0x129eaf8
2015-11-13 21:30:18.997 openLuup.server:: /data_request?id=lu_status2&output_format=json&DataVersion=471809042&Timeout=60&MinimumDelay=1500&_=1447471809415 tcp{client}: 0x129eaf8
2015-11-13 21:30:23.555 openLuup.server:: /data_request?id=exit tcp{client}: 0x1288738
2015-11-13 21:30:23.555 openLuup.scheduler:: schedule stop request after 31 jobs
2015-11-13 21:30:23.557 openLuup.server:: request completed (51 bytes, 1 chunks, 1 ms) tcp{client}: 0x1288738
2015-11-13 21:30:23.968 openLuup.server:: receive error: closed tcp{client}: 0x129eaf8
2015-11-13 21:30:23.968 openLuup.scheduler:: exiting with code 0
2015-11-13 21:30:23.968 openLuup.scheduler:: 31 jobs completed
2015-11-13 21:30:23.968 luup.reload:: saving user_data
2015-11-13 21:30:23.972 openLuup.luup:: exiting with code 0 - after 0.0 hoursWith the patched scheduler.lua: See attached file.
This was in the console when I stopped the process.
^Clua: ./openLuup/logs.lua:70: interrupted!
stack traceback:
[C]: in function 'date'
./openLuup/logs.lua:70: in function 'formatted_time'
./openLuup/logs.lua:169: in function 'send'
./openLuup/scheduler.lua:22: in function '_log'
./openLuup/scheduler.lua:79: in function <./openLuup/scheduler.lua:76>
(tail call): ?
./openLuup/scheduler.lua:365: in function 'socket_callbacks'
./openLuup/scheduler.lua:430: in function 'start'
openLuup/init.lua:201: in main chunk
[C]: ?That looks very much like you hadn’t stopped the previous copy of openLuup and it couldn’t create the server? Although it might be hard to catch, the first log on restart should show that.
OH anything is possible with my late night attempts. Ok, sequence of events …
[1] Commented out lines in rc.local so openLuup wouldn’t load on boot (a precaution so to speak).
[2] Rebooted physical server.
[3] Verified processes, openLuup is not running.
[4] Removed user_data.json
[5] Copied over all files w/in openLuup directory from latest Git.
[6] Started up with ./openLuup_reload startup.lua (just have AltUI and that’s it).
[7] Grabbed all logs created during startup.
[8] Off to grab another cup of coffee…
PID USER VSZ STAT COMMAND
1 root 15328 S /sbin/procd
2 root 0 SW [kthreadd]
3 root 0 SW [ksoftirqd/0]
4 root 0 SW [kworker/0:0]
5 root 0 SW< [kworker/0:0H]
6 root 0 SW [kworker/u8:0]
7 root 0 SW [rcu_sched]
8 root 0 SW [rcu_bh]
9 root 0 SW [migration/0]
10 root 0 SW [migration/1]
11 root 0 SW [ksoftirqd/1]
12 root 0 SW [kworker/1:0]
13 root 0 SW< [kworker/1:0H]
14 root 0 SW [migration/2]
15 root 0 SW [ksoftirqd/2]
16 root 0 SW [kworker/2:0]
17 root 0 SW< [kworker/2:0H]
18 root 0 SW [migration/3]
19 root 0 SW [ksoftirqd/3]
20 root 0 SW [kworker/3:0]
21 root 0 SW< [kworker/3:0H]
22 root 0 SW< [khelper]
23 root 0 SW< [perf]
24 root 0 SW [kworker/u8:1]
159 root 0 SW< [writeback]
160 root 0 SW< [kintegrityd]
162 root 0 SW< [bioset]
164 root 0 SW< [kblockd]
295 root 0 SW< [ata_sff]
418 root 0 SW [kswapd0]
419 root 0 SW [kworker/2:1]
483 root 0 SW [fsnotify_mark]
513 root 0 SW [kworker/0:1]
515 root 0 SW [kworker/1:1]
518 root 0 SW [kworker/3:1]
519 root 0 SW< [acpi_thermal_pm]
567 root 0 SW [scsi_eh_0]
569 root 0 SW< [scsi_tmf_0]
574 root 0 SW [scsi_eh_1]
577 root 0 SW< [scsi_tmf_1]
623 root 0 SW< [deferwq]
642 root 0 SW< [ext4-rsv-conver]
684 root 0 SW< [kworker/0:1H]
888 root 6836 S /sbin/ubusd
889 root 4716 S /sbin/askfirst /bin/ash --login
890 root 4716 S /sbin/askfirst /bin/ash --login
1016 root 0 SW< [ipv6_addrconf]
1144 root 8972 S /sbin/logd -S 16
1153 root 19412 S /sbin/rpcd
1172 root 17464 S /sbin/netifd
1194 root 11096 S /usr/sbin/odhcpd
1222 http 24188 S /usr/sbin/lighttpd -f /etc/lighttpd/lighttpd.conf
1242 root 17656 S /usr/sbin/sshd -D
1287 root 19404 S /usr/sbin/uhttpd -f -h /www -r Cobalt -x /cgi-bin -u /ubus -t 60 -T 30 -k 20 -A 1 -n 3 -N 100 -R -p 0.0.0.0:80 -p [::]:80
1327 root 9292 S udhcpc -p /var/run/udhcpc-br-lan.pid -s /lib/netifd/dhcp.script -f -t 0 -i br-lan -r 192.168.1.1 -C
1373 root 20264 R sshd: root@pts/0
1393 root 9300 S -ash
1481 root 20376 S sshd: root@notty
1492 root 9296 S ash -c /usr/lib/sftp-server
1493 root 4916 S /usr/lib/sftp-server
2668 root 9292 R psdo -- create rooms (strangely, there's no Luup command to do this directly)
local function room(n)
luup.inet.wget ("127.0.0.1:3480/data_request?id=room&action=create&name="..n)
end
room "Upstairs" -- these are persistent across restarts
room "Downstairs"
end
do -- ALTUI
local dev = luup.create_device ('', "ALTUI", "ALTUI", "D_ALTUI.xml")
enddevice 3 'ALTUI' requesting reloadAnd …
3135 root 9296 S {openLuup_reload} /bin/sh ./openLuup_reload startup.
3137 root 29540 S lua openLuup/init.luaSo this is choking on an illegal room request from luup.inet.wget in the startup.lua file.
What does your startup file look like now?
Doesn’t appear to have changed at all…
-rw-r--r-- 1 root root 935 Nov 10 16:53 startup.luado -- define top-level attributes required to personalise the installation
local attr = luup.attr_set
attr ("City_description", "None")
attr ("Country_description", "United States")
attr ("KwhPrice", "0.09")
attr ("PK_AccessPoint", "88800127")
attr ("Region_description", "None")
attr ("TemperatureFormat", "F")
attr ("currency", "$")
attr ("date_format", "mm/dd/yy")
attr ("latitude", "51.00")
attr ("longitude", "-1.00")
attr ("model", "Cobalt")
attr ("timeFormat", "24hr")
attr ("timezone", "6")
end
do -- create rooms (strangely, there's no Luup command to do this directly)
local function room(n)
luup.inet.wget ("127.0.0.1:3480/data_request?id=room&action=create&name="..n)
end
room "Upstairs" -- these are persistent across restarts
room "Downstairs"
end
do -- ALTUI
local dev = luup.create_device ('', "ALTUI", "ALTUI", "D_ALTUI.xml")
end
----------- [quote=“akbooer, post:49, topic:189395”]So this is choking on an illegal room request from luup.inet.wget in the startup.lua file.
What does your startup file look like now?[/quote]
OK, I think the versioning in my GihHub repository is screwed up again for some unknown reason (obviously my fault, not theirs!)
I’m going into deep thought mode and will probably release a complete new version. I have very extensive unit testing. This just shouldn’t be happening.
OK, sounds good to me (obviously not the part where things have gone screwy).
[quote=“akbooer, post:51, topic:189395”]OK, I think the versioning in my GihHub repository is screwed up again for some unknown reason (obviously my fault, not theirs!)
I’m going into deep thought mode and will probably release a complete new version. I have very extensive unit testing. This just shouldn’t be happening.[/quote]
@akbooer i am trying to get the DLNA plugin running on openluup on my mac. i installed wget (brew install wget) and the files from…
https://github.com/akbooer/openLuup/tree/development/openLuup
https://luarocks.org/modules/hisham/luafilesystem
http://code.mios.com/trac/mios_dlna-cntroller/browser/trunk
…into /etc/cmh-ludl (openluup files are in /etc/cmh-ludl/openluup directory of course), chmod 777 * in /etc/cmh-ludl and /etc/cmh-ludl/openluup then i did a ./openLuup_reload reset
I edited startup.lua to have only altui (no rooms, bridge, or any other devices)
Then in /etc/cmh-ludl i did a ./openLuup_reload startup.lua and i get the following errors (same errors if i run ./openLuup_reload)
mda$ ./openLuup_reload
env: lua: No such file or directory
env: lua: No such file or directory
sh: iptables: command not found
[Edit: I realized the env: errors are coming from and I don’t know how to fix it so i just changes that file to echo my IP address for now. Now i only get the “sh: iptables: command not found” error (didn’t fix the problem below).]
I used altui to create a DNLA device and…
The dlna device’s “Discover” button only discovers 1 of my DLNA renderers called “Theater & Whole Home Audio” (I have confirmed the others are online and reachable from my openluup mac). If i select the renderer it finds (which is not the one i need of course 
), i am able to send commands to it (i can not confirm the commands work until tomorrow).
But if i paste in the URL i am using in my Vera DLNA device for another DLNA render and click Select, then Check it shows the device is offline and i get these errors in the log:
mda$ grep DLNA LuaUPnP.log
015-11-15 00:15:58.302 openLuup.init:: [4] 'DNLA', urn:dlna-org:device:DLNAMediaController:1
2015-11-15 00:15:58.370 luup_log:4: DLNA: #4 starting up with id
2015-11-15 00:15:58.370 luup.variable_set:4: 4.urn:dlna-org:serviceId:DLNAMediaController1.PluginVersion was: 1.4 now: 1.4 #hooks:0
2015-11-15 00:15:58.370 luup.variable_set:4: 4.urn:dlna-org:serviceId:DLNAMediaController1.BrowseResult was: now: #hooks:0
2015-11-15 00:15:58.370 luup.variable_set:4: 4.urn:dlna-org:serviceId:DLNAMediaController1.PlaybackResult was: now: #hooks:0
2015-11-15 00:15:58.374 luup_log:4: DLNA: debug: DLNAStartup: Vera IP Address=-n 192.168.1.7
2015-11-15 00:15:58.386 luup.variable_set:4: 4.urn:dlna-org:serviceId:DLNAMediaController1.DiscoveryPatchInstalled was: 1 now: 1 #hooks:0
2015-11-15 00:15:59.650 luup_log:4: DLNA: debug: deferredDLNAStartup: start 4
2015-11-15 00:15:59.651 luup_log:4: DLNA: error: Cannot contact UPnP event proxy: connection refused
2015-11-15 00:15:59.651 luup_log:4: DLNA: UPnP proxy event identified - API version
2015-11-15 00:15:59.868 luup_log:4: DLNA: error: UPnP_getDeviceDescription wget failed - status=invalid chunk size xml=
2015-11-15 00:15:59.868 luup_log:4: DLNA: debug: upnp.setup failed: going offline
2015-11-15 00:15:59.868 luup_log:4: DLNA: debug: refreshNow: start
2015-11-15 00:16:15.110 luup_log:4: DLNA: debug: refreshNow: start
2015-11-15 00:16:17.205 openLuup.server:: /luvd/D_DLNAMediaController1.xml tcp{client}: 0x7fd2b4804228
2015-11-15 00:16:24.930 openLuup.server:: /luvd/J_DLNAMediaController1.js tcp{client}: 0x7fd2b480ca28
2015-11-15 00:16:28.136 openLuup.server:: /data_request?id=lu_action&output_format=xml&DeviceNum=4&serviceId=urn:dlna-org:serviceId:DLNAMediaController1&action=SelectDMRDevice&URL=http%3A%2F%2F192.168.1.126%3A49154%2Fdescription.xml tcp{client}: 0x7fd2b480ca28
2015-11-15 00:16:28.136 luup.call_action:: 4.urn:dlna-org:serviceId:DLNAMediaController1.SelectDMRDevice
2015-11-15 00:16:28.137 luup.variable_set:4: 4.urn:dlna-org:serviceId:DLNAMediaController1.DescriptionURL was: http://192.168.1.126:49154/description.xml now: http://192.168.1.126:49154/description.xml #hooks:0
2015-11-15 00:16:28.152 luup_log:4: DLNA: error: UPnP_getDeviceDescription wget failed - status=invalid chunk size xml=
2015-11-15 00:16:28.152 luup_log:4: DLNA: debug: upnp.setup failed: going offline
2015-11-15 00:16:30.226 luup_log:4: DLNA: debug: refreshNow: start
Would you mind pointing me in the right direction to sort this out? Thanks !
[Edit: attached is the full /etc/cmh-ludl/LuaUPnP.log]
Sadly, I know nothing about this plugin, although it appears to me to share much with the Sonos one.
I noticed this
luup_log:4: DLNA: error: UPnP_getDeviceDescription wget failed - status=invalid chunk sizeand would hazard a guess that this might mean the the device does not handle the HTTP/1.1 chunked protocol which openLuup uses.
I might be completely wrong, but it would explain why it works with one device (perhaps a newer one?) and not with others.
[quote author=akbooer link=topic=34466.msg1#msg1
and would hazard a guess that this might mean the the device does not handle the HTTP/1.1 chunked protocol which openLuup uses.
I might be completely wrong, but it would explain why it works with one device (perhaps a newer one?) and not with others.
[/quote]
Thanks, yes it should be similar to those Sonos plugin. Is there a way I can disable the chunking protocol for that device (or overall temporarily at least to test the theory?) thanks.
Sent from my iPhone using Tapatalk
You’d have to edit openLuup.server.lua
Starting at line 215:
"Content-Type: " .. type or "text/plain",
-- "Content-Length: " .. #response,
"Transfer-Encoding: Chunked",
"Connection: keep-alive",
crlf}, crlf)
send (sock, headers)
local ok, err, nc = send_chunked (sock, response, 16000)change it to this:
"Content-Type: " .. type or "text/plain",
"Content-Length: " .. #response,
-- "Transfer-Encoding: Chunked", -- <-- comment out
"Connection: keep-alive",
crlf}, crlf)
send (sock, headers)
local ok, err, nc = send (sock, response) -- <-- change from send_chunked
nc = 1This should just remove chunked encoding entirely. I will be really interested to learn how this goes both in general and for DLNA in particular.
Good luck.
Edit: code additions /changes
[quote=“akbooer, post:56, topic:189395”]You’d have to edit openLuup.server.lua
…
This should just remove chunked encoding entirely. I will be really interested to learn how this goes both in general and for DLNA in particular.[/quote]
@akbooer, i made the changes to server.lua in the openluup directory as you described so my server.lua file now has this:
"Content-Type: " .. type or "text/plain",
-- "Content-Length: " .. #response,
-- "Transfer-Encoding: Chunked", -- <-- comment out
"Connection: keep-alive",
crlf}, crlf)
send (sock, headers)
local ok, err, nc = send (sock, response) -- <-- change from send_chunked
nc = 1
return #(response or {}), nc
end
I did a ./openLuup_reload reset then ./openLuup_reload startup.lua then ./openLuup_reload
It looks like it is getting stuck on J_ALTUI_uimgr.js (chrome develop tools screen shot attached).
My log is attached starting from the./openLuup_reload
Thanks.
-mda
[ol][li]I presume that, in fact, the line with ContentLength header is NOT commented out?[/li]
[li]yes, that’s the error which chunked encoding seeks to fix.[/li][/ol]
I’m looking further into the timeout issue, but I’ve spent a great deal of effort on it in the past too. Chunked encoding was a last resort. It even has a small delay in there to slow things down. Very obscure error.
I think I failed to uncomment the ContentLength line. I will check as soon as I get so a computer later today. Thanks!
Sent from my iPhone using Tapatalk[/list]
[ul][quote=“akbooer, post:58, topic:189395”][list type=decimal]
[li]I presume that, in fact, the line with ContentLength header is NOT commented out?[/li][/list][/quote]
I uncommented the ContentLength line. Now AltUI does load but the problem with the DLNA plug-in is still there:
server.lua now looks like this:[/ul]
"Content-Type: " .. type or "text/plain",
"Content-Length: " .. #response,
-- "Transfer-Encoding: Chunked", -- <-- comment out
"Connection: keep-alive",
crlf}, crlf)
send (sock, headers)
local ok, err, nc = send (sock, response) -- <-- change from send_chunked
nc = 1
I still get the iptables error when i start openluup:
mda$ ./openLuup_reload
sh: iptables: command not found
My log is attached.
Thanks.