Merge branch 'develop'

Conflicts:
	README.md

Makefile

@@ -66,6 +66,13 @@ define Build/Compile directives
 #	no compilation necessary (although possible with luac?)
 endef
 
+# This information is contained within the ipk file and (at least) used by
+# sysupgrade to determine which files to keep (see `opkg list-changed-conffiles`).
+define Package/wifibox/conffiles
+/etc/config/wifibox
+/etc/logrotate.d/wifibox.conf
+endef
+
 # The $(1) variable represents the root directory on the router running 
 # OpenWrt. The $(INSTALL_DIR) variable contains a command to prepare the install 
 # directory if it does not already exist.  Likewise $(INSTALL_BIN) contains the 
@@ -88,6 +95,9 @@ define Package/wifibox/install
 	#$(INSTALL_DIR) $(1)/etc
 	$(INSTALL_DIR) $(1)/etc/init.d
 	$(INSTALL_DIR) $(1)/etc/config
+	$(INSTALL_DIR) $(1)/etc/logrotate.d
+	$(INSTALL_DIR) $(1)/root/
+	$(INSTALL_DIR) $(1)/root/sketches
 	#$(INSTALL_DIR) $(1)/www
 	$(INSTALL_DIR) $(1)/www/cgi-bin
 	
@@ -102,10 +112,14 @@ define Package/wifibox/install
 	
 	$(INSTALL_BIN) $(WIFIBOX_BASE_DIR)/script/d3d-updater.lua $(1)/$(TGT_LUA_DIR_SUFFIX)/script
 	$(LN) -s /$(TGT_LUA_DIR_SUFFIX)/script/d3d-updater.lua $(1)/bin/d3d-updater
+	$(CP) $(WIFIBOX_BASE_DIR)/script/loglite-filters.lua $(1)/root/
+	$(INSTALL_BIN) $(WIFIBOX_BASE_DIR)/script/loglite.lua $(1)/$(TGT_LUA_DIR_SUFFIX)/script
+	$(LN) -s /$(TGT_LUA_DIR_SUFFIX)/script/loglite.lua $(1)/bin/loglite
 	$(INSTALL_BIN) $(WIFIBOX_BASE_DIR)/script/wifibox_init $(1)/etc/init.d/wifibox
 	$(INSTALL_BIN) $(WIFIBOX_BASE_DIR)/script/dhcpcheck_init $(1)/etc/init.d/dhcpcheck
 	$(INSTALL_BIN) $(WIFIBOX_BASE_DIR)/script/d3dapi $(1)/$(TGT_LUA_DIR_SUFFIX)/script
 	$(INSTALL_BIN) $(WIFIBOX_BASE_DIR)/script/signin.sh $(1)/$(TGT_LUA_DIR_SUFFIX)/script
+	$(CP) $(WIFIBOX_BASE_DIR)/script/logrotate-wifibox.conf $(1)/etc/logrotate.d/wifibox.conf
 	
 	$(CP) $(WIFIBOX_BASE_DIR)/script/wifibox.uci.config $(1)/etc/config/wifibox  # copy base configuration to uci config dir
 	$(CP) $(WIFIBOX_BASE_DIR)/FIRMWARE-VERSION $(1)/etc/wifibox-version

README.md

@@ -3,6 +3,7 @@ WiFi box OpenWRT firmware package
 
 General documentation can be found on the wiki: <http://doodle3d.com/help/wiki>. Source code documentation can be generated, see below.
 
+
 Documentation
 -------------
 
@@ -11,7 +12,6 @@ Make sure the 'ldoc' program is installed on your machine and the LDOC variable
 
 On OSX, this can be accomplished by installing it through luarocks (run `sudo luarocks install ldoc`). Luarocks can be installed using [MacPorts](http://www.macports.org/). After installing that, the command would be `sudo port install luarocks`.
 
-
 Command line interface
 ----------------------
 The Doodle3D API can be called using a terminal:
@@ -24,3 +24,16 @@ Post request can be send using the same method:
 ```d3dapi p=/printer/print r=POST```
 
 Parameters: TODO
+
+Debugging Lua
+-------------
+
+Syntax errors in Lua can lead to tricky issues since they might only surface when the faulty code is actually being run.
+
+One countermeasure for this is to use [pcall](http://www.lua.org/pil/8.4.html) instead of regular calls in many cases. To let the error 'happen' (which in turn gives information in the form of stack traces), tell the code to use regular calls by setting 'M.DEBUG_PCALLS' to 'true' in `conf_defaults.lua`.
+
+Additionally, when the pcall setting is not enough, a second way of debugging is to take uhttpd out of the loop and invoke the Lua code from command-line. To do this, set 'M.DEBUG_API' to 'true' in `conf_defaults.lua`. Then invoke the API using the command `d3dapi p=/mod/func r=POST` where `p=` is followed by the API path and `r=` followed by either 'GET' or 'POST'.
+
+Note that because stack traces are sent to `stderr`, this script redirects output streams to a separate log file: `/tmp/wifibox.stdout.log`; apart from these traces, the file should not contain any data.
+
+Finally, the `CGI` gateway of uhttpd also uses this script, so the API can also be used to obtain stack traces by calling it as `<wifibox-ip>/cgi-bin/d3dapi/<endpoint>` (note the extra `cgi-bin`).

ReleaseNotes.md

@@ -1,4 +1,43 @@
 Changelog
+# 0.10.10 (11 may 2016)
+- Logging client version info to console.  
+- Logging less when printing to makerbot/wanhao
+- Logging API time info
+- Included version number file in logfiles
+- Fixed stopping while sending
+
+# 0.10.10-e (21 apr 2016)
+- Fixed Makerbot end gcode that prevented prints or stopping prints to finish.
+
+# 0.10.10-d (20 apr 2016)
+- Allow print part sequence numbers to be retrieved
+- Sequence numbers are send back when sending print parts
+- When WiFi-Box responds that print part was already received the client will send the next part.
+
+# 0.10.10-c (1 apr 2016)
+- Quicker log rotation
+
+# 0.10.10-b (21 mrt 2016)
+- Logrotation (making sure older logs are removed)
+- Improved logging.
+- Always log initial printer communication
+- loglite improvements, added readme
+
+# 0.10.10-a (24 feb 2016)
+- Max buffer size check: the WiFi-Box can now indicate through the API that its buffer is full and it won't accept new gcode.
+- Buffer information is communicated through the API so all clients can handle this properly. The Doodle3D client will stop sending and waits until it drops below 75%. It will check this every 30 seconds.
+- Improved progress indication: when sending a print the total number of lines can be added, causing the total lines reported through the API to be correct, instead of being approximated to be total lines in buffer, which keeps increasing while a print is still being sent.
+- When sending print parts, sequence numbers can be added which will be checked for correctness.
+- The stop button now stays enabled while still sending a print.
+- Made firmware log format consistent with print3d's.
+- Fixed local IP parsing pattern in firmware.
+- Improved log messages and log messages formatting.
+- Added loglite utility which enables filtering and coloring of logs.
+- Won't attempt sign-in when in access point mode.
+- More consistent error reporting from API.
+- API d3dapi/printer/print's 'first' parameter has been deprecated in favor of a more descriptive 'clear' parameter.
+- Support for CraftBot PLUS printer.
+
 # 0.10.9 (11 jan 2016)
 # 0.10.8 (11 jan 2016)
 # 0.10.8-b (7 jan 2016)

extra/openwrt-build/openwrt-diffconfig-extramini

@@ -22,8 +22,10 @@ CONFIG_PACKAGE_kmod-usb-serial-ftdi=y
 # CONFIG_PACKAGE_libip6tc is not set
 CONFIG_PACKAGE_libiwinfo=y
 CONFIG_PACKAGE_libiwinfo-lua=y
+CONFIG_PACKAGE_libpopt=y
 CONFIG_PACKAGE_liblua=y
 CONFIG_PACKAGE_libuci-lua=y
+CONFIG_PACKAGE_logrotate=y
 CONFIG_PACKAGE_lua=y
 CONFIG_PACKAGE_luafilesystem=y
 # CONFIG_PACKAGE_odhcp6c is not set

extra/openwrt-build/openwrt-diffconfig-mini

@@ -20,8 +20,10 @@ CONFIG_PACKAGE_kmod-usb-serial-ftdi=y
 # CONFIG_PACKAGE_libip6tc is not set
 CONFIG_PACKAGE_libiwinfo=y
 CONFIG_PACKAGE_libiwinfo-lua=y
+CONFIG_PACKAGE_libpopt=y
 CONFIG_PACKAGE_liblua=y
 CONFIG_PACKAGE_libuci-lua=y
+CONFIG_PACKAGE_logrotate=y
 CONFIG_PACKAGE_lua=y
 CONFIG_PACKAGE_luafilesystem=y
 # CONFIG_PACKAGE_odhcp6c is not set

extra/openwrt-build/openwrt-diffconfig-regular

@@ -9,8 +9,10 @@ CONFIG_PACKAGE_kmod-usb-serial=y
 CONFIG_PACKAGE_kmod-usb-serial-ftdi=y
 CONFIG_PACKAGE_libiwinfo=y
 CONFIG_PACKAGE_libiwinfo-lua=y
+CONFIG_PACKAGE_libpopt=y
 CONFIG_PACKAGE_liblua=y
 CONFIG_PACKAGE_libuci-lua=y
+CONFIG_PACKAGE_logrotate=y
 CONFIG_PACKAGE_lua=y
 CONFIG_PACKAGE_luafilesystem=y
 CONFIG_PACKAGE_print3d=y

extra/scripts/publish-wifibox-release.lua

@@ -129,10 +129,16 @@ local function quit(ev)
 end
 
 local function md5sum(file)
+	-- try OS X specific md5 utility
 	local rv,_,sum = pl.utils.executeex('md5 -q "' .. file .. '"')
-
+	if rv then
 		return rv and sum:sub(1, -2) or nil
 	end
+	-- try Linux md5sum utility
+	local rv,_,output = pl.utils.executeex('md5sum "' .. file .. '"')
+	local md5 = string.match(output, "[^%s]+")
+	return md5
+end
 
 local function getYesNo(question)
 	local answer

license-spec.lua

@@ -1,6 +1,6 @@
 local M = {
 	BASE_PATH = 'src',
-	EXCLUDE_FILES = { 'src/util/JSON.lua', 'src/util/urlcode.lua' },
+	EXCLUDE_FILES = { 'src/util/JSON.lua', 'src/util/urlcode.lua', 'src/script/loglite%-filters.lua' },
 	PROCESS_FILES = {
 		['src/[^/]*%.lua'] = 'lua',
 		['src/network/[^/]*%.lua'] = 'lua',

post-install.sh

@@ -36,9 +36,9 @@ addFirewallNet() {
 ### Replace the banner with a custom one
 if [ ! -f $IPKG_INSTROOT/etc/banner.default ]; then
 	mv $IPKG_INSTROOT/etc/banner $IPKG_INSTROOT/etc/banner.default
-	cat <<-'EOM' > $IPKG_INSTROOT/etc/banner
+	cat <<-\EOM > $IPKG_INSTROOT/etc/banner
 		........D o o d l e 3 D
-		.......________     _____  _____  v \$(PACKAGE_VERSION)
+		.......________     _____  _____
 		....../  /  /  |__ /  __/ /  - /___ __
 		...../  /  /  /--//  _|-//  --| . /v /
 		..../________/__//__/__//____/___/_^_\
@@ -52,17 +52,23 @@ fi
 mkdir -p $IPKG_INSTROOT/root
 grep '^# DO NOT MODIFY.*wifibox package.$' $IPKG_INSTROOT/root/.profile >/dev/null 2>&1
 if [ $? -gt 0 ]; then
-		cat <<-EOM >> $IPKG_INSTROOT/root/.profile
+	cat <<-\EOM >> $IPKG_INSTROOT/root/.profile
-
 		# DO NOT MODIFY - this block of lines has been added by the wifibox package.
 		alias d='ls -la'
 		alias d3dapi='/usr/share/lua/wifibox/script/d3dapi'
 		alias encore='ulimit -c unlimited'
 		alias wopkg='opkg -f /usr/share/lua/wifibox/opkg.conf'
 
+		alias tailfw='loglite /tmp/wifibox.log firmware'
+		tailp3d() {
+		  logfile=/tmp/print3d-ttyACM0.log
+		  if [ $# -gt 0 ]; then logfile=$1; fi
+		  loglite "$logfile" print3d
+		}
+
 		loop() {
-			if [ \$# -lt 2 ]; then echo "Please supply a delay and a command."; return 1; fi
+		  if [ $# -lt 2 ]; then echo "Please supply a delay and a command."; return 1; fi
-			DELAY=\$1; shift; while true; do \$@; sleep \$DELAY; done
+		  DELAY=$1; shift; while true; do $@; sleep $DELAY; done
 		}
 EOM
 fi
@@ -70,11 +76,11 @@ fi
 #preserve saved sketches during firmware update
 echo "/root/sketches" >> $IPKG_INSTROOT/etc/sysupgrade.conf
 
+
+
 ### Finally make sure basic configuration is set correctly
 
-$IPKG_INSTROOT/etc/init.d/wifibox enable
+LOGROTATE_CRON_LINE="*/2 *   *   *   *   /usr/sbin/logrotate /etc/logrotate.conf"
-$IPKG_INSTROOT/etc/init.d/wifibox start
-$IPKG_INSTROOT/etc/init.d/dhcpcheck enable
 
 if [ -z "$IPKG_INSTROOT" ]; then
 	# No installation root, we are being installed on a live box so run uci commands directly.
@@ -99,6 +105,13 @@ if [ -z "$IPKG_INSTROOT" ]; then
 	uci -q delete wifibox.system.loglevel  # remove key used in older versions (<=0.10.8a) if it exists
 	uci commit wifibox
 
+	crontab -l 2> /dev/null | grep logrotate\.conf > /dev/null
+	if [ $? -ne 0 ]; then
+		# add line, method from http://askubuntu.com/a/58582
+		# Note: `crontab -l` will throw an error to stderr because the file does not exist, but that does not matter
+		(crontab -l 2> /dev/null; echo "$LOGROTATE_CRON_LINE" ) | crontab -
+	fi
+
 else
 	# Create a script to setup the system as wifibox, it will be deleted after it has been run, except if it returns > 0.
 
@@ -121,10 +134,23 @@ else
 	uci set wifibox.general.system_log_level='info'
 	uci -q delete wifibox.system.loglevel  # remove key used in older versions (<=0.10.8a) if it exists
 
+	crontab -l 2> /dev/null | grep logrotate\.conf > /dev/null
+	if [ $? -ne 0 ]; then
+		# add line, method from http://askubuntu.com/a/58582
+		# Note: `crontab -l` will throw an error to stderr because the file does not exist, but that does not matter
+		(crontab -l 2> /dev/null; echo "$LOGROTATE_CRON_LINE" ) | crontab -
+	fi
+
 	exit 0
 EOM
 
 	echo "WARNING: WiFiBox network configuration can only be fully prepared when installing on real device"
 fi
 
+$IPKG_INSTROOT/etc/init.d/wifibox enable
+$IPKG_INSTROOT/etc/init.d/wifibox start
+$IPKG_INSTROOT/etc/init.d/dhcpcheck enable
+$IPKG_INSTROOT/etc/init.d/cron enable
+$IPKG_INSTROOT/etc/init.d/cron start
+
 exit 0

src/FIRMWARE-VERSION

@@ -1 +1 @@
-0.10.9
+0.10.10

src/conf_defaults.lua

@@ -36,6 +36,8 @@ M.DEBUG_PCALLS = false
 
 --- This constant enables debugging of the REST API from the command-line by emulating GET/POST requests.
 -- Specify the path and optionally the request method as follows: `d3dapi p=/mod/func r=POST`.
+-- Note that the command-line script redirects the output streams to '/tmp/wifibox.stdout.log',
+-- meaning that any stack traces can be found there.
 M.DEBUG_API = true
 
 --- If enabled, REST responses will contain 'module' and 'function' keys describing what was requested.
@@ -131,6 +133,7 @@ M.printer_dimensions_x = {
 	default_colido_2_0_plus = 230,
 	default_colido_x3045 = 300,
 	default_colido_compact = 130,
+	default_craftbot_plus = 250,
 	subSection = 'printer_type',
 	type = 'int',
 	description = '',
@@ -182,6 +185,7 @@ M.printer_heatedbed = {
 	default_colido_2_0_plus = true,
 	default_colido_m2020 = true,
 	default_colido_x3045 = true,
+	default_craftbot_plus = true,
 	subSection = 'printer_type',
 	type = 'bool',
 	description = 'Printer has heated bed',
@@ -190,6 +194,7 @@ M.printer_filamentThickness = {
 	default = 2.89,
 	default_doodle_dream = 1.75,
 	default_wanhao_duplicator4 = 1.75,
+	default_craftbot_plus = 1.75,
 	type = 'float',
 	description = '',
 	min = 0.0,
@@ -217,7 +222,7 @@ M.printer_startcode = {
 	description = ''
 }
 
-local default_makerbot_endcode = 'M73 P100\nG92 A0 B0 ;reset extruder position to prevent retraction\nM18 A B(Turn off A and B Steppers)\nG162 Z F900\nG162 X Y F2000\nM18 X Y Z(Turn off steppers after a build)\n{if heatedBed}M140 S{preheatBedTemp} T0\nM104 S{preheatTemp} T0\nM73 P100 (end  build progress )\nM72 P1  ( Play Ta-Da song )\nM137 (build end notification)'
+local default_makerbot_endcode = 'G92 A0 B0 ;reset extruder position to prevent retraction\nM18 A B(Turn off A and B Steppers)\nG162 Z F900\nG162 X Y F2000\nM18 X Y Z(Turn off steppers after a build)\n{if heatedBed}M140 S{preheatBedTemp} T0\nM104 S{preheatTemp} T0\nM72 P1  ( Play Ta-Da song )\nM137 (build end notification)'
 local default_deltabot_endcode = 'M107 ;fan offG91 ;relative positioningG1 E-1 F300 ;retract the filament a bit before lifting the nozzle, to release some of the pressureG1 Z+0.5 E-5 X-20 Y-20 F9000 ;move Z up a bit and retract filament even moreG28 ;move to homeM84 ;disable axes / steppersG90 ;absolute positioningM109 S0 ; hot end off{if heatedBed}M140 S{preheatBedTemp}M117 Done                 ;display message (20 characters to clear whole screen)'
 local default_ultimaker2_endcode = 'M107 ;fan off\nG91 ;relative positioning\nG1 E-1 F300 ;retract the filament a bit before lifting the nozzle, to release some of the pressure\nG1 Z+5.5 E-5 X-20 Y-20 F9000 ;move Z up a bit and retract filament even more\nG28 ;home the printer\nM84 ;disable axes / steppers\nG90 ;absolute positioning\nM104 S{preheatTemp}\n{if heatedBed}M140 S{preheatBedTemp}\nM117 Done                 ;display message (20 characters to clear whole screen)'
 M.printer_endcode = {
@@ -233,6 +238,7 @@ M.printer_endcode = {
 	default_delta_rostockmax = default_deltabot_endcode,
 	default_deltamaker = default_deltabot_endcode,
 	default_kossel = default_deltabot_endcode,
+	default_craftbot_plus = 'M107 ;fan off\nG91 ;relative positioning\nG1 E-1 F300 ;retract the filament a bit before lifting the nozzle, to release some of the pressure\nG1 Z+0.5 E-5 X-20 Y-20 F9000 ;move Z up a bit and retract filament even more\nG28 X0 Y0 ;move X/Y to min endstops, so the head is out of the way\nM84 ;disable axes / steppers\nG90 ;absolute positioning\nM109 S{preheatTemp}\n{if heatedBed}M140 S{preheatBedTemp}\nM117 Done                 ;display message (20 characters to clear whole screen)',
 	type = 'string',
 	subSection = 'printer_type',
 	description = ''

src/main.lua

@@ -22,6 +22,8 @@ local netconf = require('network.netconfig')
 local RequestClass = require('rest.request')
 local ResponseClass = require('rest.response')
 local Signin = require('network.signin')
+local osUtils = require('os_utils')
+
 
 -- NOTE: the updater module 'detects' command-line invocation by existence of 'arg', so we have to make sure it is not defined.
 argStash = arg
@@ -30,6 +32,7 @@ local updater = require('script.d3d-updater')
 arg = argStash
 
 local postData = nil
+local MOD_ABBR = "ENTR"
 
 
 --- Switches to wifi client mode or to access point mode based on availability of known wifi networks.
@@ -48,11 +51,11 @@ local function setupAutoWifiMode()
 
 	local wifiState = wifi.getDeviceState()
 	local netName, netMode = wifiState.ssid, wifiState.mode
-	log:info("current wifi name: " .. (netName or "<nil>") .. ", mode: " .. netMode)
+	log:info(MOD_ABBR, "current wifi name: " .. (netName or "<nil>") .. ", mode: " .. netMode)
 
 	local apSsid = wifi.getSubstitutedSsid(settings.get('network.ap.ssid'))
 	local apMode = (apSsid == netName) and (netMode == 'ap')
-	log:info("ssid of self: " .. apSsid)
+	log:info(MOD_ABBR, "ssid of self: " .. apSsid)
 
 	local scanList,msg = wifi.getScanInfo()
 	if not scanList then
@@ -60,7 +63,7 @@ local function setupAutoWifiMode()
 	end
 
 	local knownSsids = wifi.getConfigs()
-	-- log:info("current wifi name: " .. (netName or "<nil>") .. ", mode: " .. netMode .. ", ssid of self: " .. apSsid)
+	-- log:info(MOD_ABBR, "current wifi name: " .. (netName or "<nil>") .. ", mode: " .. netMode .. ", ssid of self: " .. apSsid)
 	local visNet, knownNet = {}, {}
 	for _,sn in ipairs(scanList) do
 		table.insert(visNet, sn.ssid)
@@ -68,17 +71,17 @@ local function setupAutoWifiMode()
 	for _,kn in ipairs(knownSsids) do
 		table.insert(knownNet, kn.ssid .. "/" .. kn.mode)
 	end
-	log:info("visible networks: " .. table.concat(visNet, ", "))
+	log:info(MOD_ABBR, "visible networks: " .. table.concat(visNet, ", "))
-	log:info("known networks: " .. table.concat(knownNet, ", "))
+	log:info(MOD_ABBR, "known networks: " .. table.concat(knownNet, ", "))
 
 	-- if the currently active network is client mode and is also visible, do nothing since it will connect automatically further along the boot process
 	if netMode == 'sta' and netName ~= nil and netName ~= "" and findSsidInList(scanList, netName) then
 		-- signin to connect.doodle3d.com
 		local success, output = Signin.signin()
 		if success then
-				log:info("Signed in")
+				log:info(MOD_ABBR, "Signed in")
 		else 
-			log:info("Signing in failed")
+			log:info(MOD_ABBR, "Signing in failed")
 		end
 		-- report we are connected after signin attempt
 		netconf.setStatus(netconf.CONNECTED,"Connected");
@@ -119,41 +122,57 @@ local function setupAutoWifiMode()
 end
 
 --- Initializes the logging system to use the file and level defined in the system settings.
--- The settings used are `logfile` and `loglevel`. The former may either be a
+-- The settings used are `log_path`, `api_log_filename` from the system section and
--- reular file path, or `<stdout>` or `<stderr>`.
+-- `system_log_level` from the general section. The filename may either be a regular filename
+-- (with an absolute log_path), or `<stdout>` or `<stderr>`.
+-- TODO: also support backticks (see Logger.cpp in print3d)--
 -- @see util.settings.getSystemKey
 -- @treturn bool True on success, false on error.
 local function setupLogger()
 	local logStream = io.stderr -- use stderr as hard-coded default target
-	local logLevel = log.LEVEL.debug -- use debug logging as hard-coded default level
+	local logLevel = log.LEVEL.verbose -- use verbose logging as hard-coded default level
 
-	local logTargetSetting = settings.getSystemKey('logfile')
+	local logPathSetting = settings.getSystemKey('log_path')
-	local logLevelSetting = settings.get('system.log.level')
+	local logTargetSetting = settings.getSystemKey('api_log_filename')
+	local logLevelSetting = settings.get('system_log_level')
 	local logTargetError, logLevelError = nil, nil
 
-	-- TEMP: for now, translate print3d log level to firmware level, these will be unfiied in the future
-	-- we get (print3d): quiet,error,warning,info,verbose,bulk -- and we need (firmware): debug,info,warn,error,fatal
-	logLevelMapping = { quiet='fatal', error='error', warning='warn', info='warn', verbose='info', bulk='debug' }
-	logLevelSetting = logLevelMapping[logLevelSetting]
-
 	if type(logTargetSetting) == 'string' then
-		local specialTarget = logTargetSetting:match('^<(.*)>$')
+		local streamTarget = logTargetSetting:match('^<(.*)>$')
-		if specialTarget then
+		local popenTarget = logTargetSetting:match('^`(.*)`$')
-			if specialTarget == 'stdout' then logStream = io.stdout
+		if streamTarget then
-			elseif specialTarget == 'stderr' then logStream = io.stderr
+			if streamTarget:lower() == 'stdout' then logStream = io.stdout
+			elseif streamTarget:lower() == 'stderr' then logStream = io.stderr
 			end
-		elseif logTargetSetting:sub(1, 1) == '/' then
+		elseif popenTarget then
-			local f,msg = io.open(logTargetSetting, 'a+')
+			local f,msg = io.popen(popenTarget, 'w')
 
 			if f then logStream = f
 			else logTargetError = msg
 			end
+		elseif logPathSetting:sub(1, 1) == '/' then
+			local path = logPathSetting .. '/' .. logTargetSetting
+			local f,msg = io.open(path, 'a+')
+
+			if f then
+				logStream = f
+				log:setLogFilePath(path)
+			else
+				logTargetError = msg
+			end
+		else
+			logTargetError = "log file path is not absolute"
 		end
 	else
 		-- if uci config not available, fallback to /tmp/wifibox.log
-		local f,msg = io.open('/tmp/wifibox.log', 'a+')
+		local path = '/tmp/wifibox.log'
-		if f then logStream = f
+		local f,msg = io.open(path, 'a+')
-		else logTargetError = msg
+
+		if f then
+			logStream = f
+			log:setLogFilePath(path)
+		else
+			logTargetError = msg
 		end
 	end
 
@@ -173,12 +192,12 @@ local function setupLogger()
 
 	local rv = true
 	if logTargetError then
-		log:error("could not open logfile '" .. logTargetSetting .. "', using stderr as fallback (" .. logTargetError .. ")")
+		log:error(MOD_ABBR, "could not open logfile '" .. logPathSetting .. '/' .. logTargetSetting .. "', using stderr as fallback (" .. logTargetError .. ")")
 		rv = false
 	end
 
 	if logLevelError then
-		log:error("uci config specifies invalid log level '" .. logLevelSetting .. "', using debug level as fallback")
+		log:error(MOD_ABBR, "uci config specifies invalid log level '" .. logLevelSetting .. "', using verbose level as fallback")
 		rv = false
 	end
 
@@ -189,17 +208,6 @@ end
 -- The logger is set up, any POST data is read and several other subsystems are initialized.
 -- @tparam table environment The 'shell' environment containing all CGI variables. Note that @{cmdmain} simulates this.
 local function init(environment)
-	setupLogger()
-
-	local dbgText = ""
-	if confDefaults.DEBUG_API and confDefaults.DEBUG_PCALLS then dbgText = "pcall+api"
-	elseif confDefaults.DEBUG_API then dbgText = "api"
-	elseif confDefaults.DEBUG_PCALL then dbgText = "pcall"
-	end
-
-	if dbgText ~= "" then dbgText = " (" .. dbgText .. " debugging)" end
-	log:info("=======rest api" .. dbgText .. "=======")
-
 	if (environment['REQUEST_METHOD'] == 'POST') then
 		local n = tonumber(environment['CONTENT_LENGTH'])
 		postData = io.read(n)
@@ -224,48 +232,45 @@ local function main(environment)
 	if rq:getRequestMethod() == 'CMDLINE' and rq:get('autowifi') ~= nil then
 
 		local version = updater.formatVersion(updater.getCurrentVersion());
-		log:info("Doodle3D version: "..util.dump(version))
+		log:info(MOD_ABBR, "Doodle3D version: "..util.dump(version))
 
-		log:info("running in autowifi mode")
+		log:info(MOD_ABBR, "Running in autowifi mode")
 		local rv,msg = setupAutoWifiMode()
 
 		if rv then
-			log:info("autowifi setup done (" .. msg .. ")")
+			log:info(MOD_ABBR, "Autowifi setup done (" .. msg .. ")")
 		else
-			log:error("autowifi setup failed (" .. msg .. ")")
+			log:error(MOD_ABBR, "Autowifi setup failed (" .. msg .. ")")
 		end
 	elseif rq:getRequestMethod() == 'CMDLINE' and rq:get('signin') ~= nil then
-		log:info("running in signin mode")
+		log:info(MOD_ABBR, "Running in signin mode")
 
-		local ds = wifi.getDeviceState()
+		log:info(MOD_ABBR, "  attempting signin")
-		log:info("  ds.mode: "..util.dump(ds.mode))
-		if ds.mode == "sta" then
-			log:info("  attempting signin")
 		local success,msg = Signin.signin()
 		if success then
-		  		log:info("Signin successful")
+	  		log:info(MOD_ABBR, "Signin successful")
 		else
-				log:info("Signin failed: "..util.dump(msg))
+			log:warning(MOD_ABBR, "Signin failed: "..util.dump(msg))
-			end
 		end
 	elseif rq:getRequestMethod() ~= 'CMDLINE' or confDefaults.DEBUG_API then
-	--	log:info("received request of type " .. rq:getRequestMethod() .. " for " .. (rq:getRequestedApiModule() or "<unknown>")
+		-- Note: the commented log message will print too many data if it's for instance dumping a gcode add request
-	--			.. "/" .. (rq:getRealApiFunctionName() or "<unknown>") .. " with arguments: " .. util.dump(rq:getAll()))
+		--logMessage = "received request of type " .. rq:getRequestMethod() .. " for " .. (rq:getRequestedApiModule() or "<unknown>")
-		log:info("received request of type " .. rq:getRequestMethod() .. " for " .. (rq:getRequestedApiModule() or "<unknown>")
+		--		.. "/" .. (rq:getRealApiFunctionName() or "<unknown>") .. " with arguments: " .. util.dump(rq:getAll())
-				.. "/" .. (rq:getRealApiFunctionName() or "<unknown>"))
+		logMessage = rq:getRequestMethod() .. " request for " .. (rq:getRequestedApiModule() or "<unknown>")
+				.. "/" .. (rq:getRealApiFunctionName() or "<unknown>")
 		if rq:getRequestMethod() ~= 'CMDLINE' then
-			log:info("remote IP/port: " .. rq:getRemoteHost() .. "/" .. rq:getRemotePort())
+			logMessage = logMessage .. " (remote IP/port: " .. rq:getRemoteHost() .. "/" .. rq:getRemotePort() .. ")"
-			--log:debug("user agent: " .. rq:getUserAgent())
+			--logMessage = logMessage .. " (user agent: " .. rq:getUserAgent() .. ")"
 		end
+		log:info(MOD_ABBR, logMessage)
 
 		local response, err = rq:handle()
 
-		if err ~= nil then log:error(err) end
+		if err ~= nil then log:error(MOD_ABBR, err) end
 		response:send()
-
 		response:executePostResponseQueue()
 	else
-		log:info("Nothing to do...bye.\n")
+		log:info(MOD_ABBR, "Nothing to do...bye.\n")
 	end
 end
 
@@ -278,6 +283,22 @@ end
 -- @tparam table env The CGI environment table.
 -- @treturn number A Z+ return value suitable to return from wrapper script. Note that this value is ignored by uhttpd-mod-lua.
 function handle_request(env)
+	local function constructDebugText()
+		local dbgText = ""
+		if confDefaults.DEBUG_API and confDefaults.DEBUG_PCALLS then dbgText = "pcall+api"
+		elseif confDefaults.DEBUG_API then dbgText = "api"
+		elseif confDefaults.DEBUG_PCALL then dbgText = "pcall"
+		end
+		if dbgText ~= "" then dbgText = " (" .. dbgText .. " debugging)" end
+		return dbgText
+	end
+
+	setupLogger()
+
+	local pid = osUtils.getPID()
+	local beginSecs, beginUSecs = osUtils.getTime()
+
+	log:verbose(MOD_ABBR, "START-RQ with PID=" .. pid .. constructDebugText())
 	local s, msg = init(env)
 
 	if s == false then
@@ -286,11 +307,13 @@ function handle_request(env)
 
 		resp:setError("initialization failed" .. errSuffix)
 		resp:send()
-		log:error("initialization failed" .. errSuffix) --NOTE: this assumes the logger has been initialized properly, despite init() having failed
+		log:error(MOD_ABBR, "Initialization failed" .. errSuffix)
 
 		return 1
 	else
 		main(env)
+		local elapsed,msg = osUtils.getElapsedTime(beginSecs, beginUSecs)
+		log:bulk(MOD_ABBR, "END-RQ with PID=" .. pid .. " completed in " .. elapsed .. " msec")
 		return 0
 	end
 end

src/network/netconfig.lua

@@ -18,6 +18,8 @@ local reconf = {}
 local wifi
 local reloadSilent
 
+local MOD_ABBR = "NTCF"
+
 M.WWW_CAPTIVE_PATH = '/usr/share/lua/wifibox/www'
 M.WWW_CAPTIVE_INDICATOR = '/www/.wifibox-inplace'
 M.WWW_RENAME_NAME = '/www-regular'
@@ -62,10 +64,10 @@ function M.switchConfiguration(components)
 	for k,v in pairs(components) do
 		local fname = k .. '_' .. v
 		if type(reconf[fname]) == 'function' then
-			log:debug("reconfiguring component '" .. k .. "' (" .. v .. ")")
+			log:verbose(MOD_ABBR, "reconfiguring component '" .. k .. "' (" .. v .. ")")
 			reconf[fname](dirtyList)
 		else
-			log:warn("unknown component or action '" .. fname .. "' skipped")
+			log:warning(MOD_ABBR, "unknown component or action '" .. fname .. "' skipped")
 		end
 	end
 
@@ -79,12 +81,12 @@ function M.switchConfiguration(components)
 end
 
 function M.commitComponent(c)
-	log:info("committing component '" .. c .. "'")
+	log:verbose(MOD_ABBR, "committing component '" .. c .. "'")
 	uci:commit(c)
 end
 
 function M.reloadComponent(c, silent)
-	log:info("reloading component '" .. c .. "'") 
+	log:verbose(MOD_ABBR, "reloading component '" .. c .. "'")
 	local command = 'reload'
 	local cmd = '/etc/init.d/' .. c .. ' '..command
 	if silent ~= nil and silent then
@@ -92,7 +94,7 @@ function M.reloadComponent(c, silent)
 		os.execute(cmd)
 	else
 		rv = utils.captureCommandOutput(cmd)
-		log:debug("  result reloading component '" .. c .. "' (cmd: '"..cmd.."'): \n"..utils.dump(rv))
+		log:verbose(MOD_ABBR, "  result reloading component '" .. c .. "' (cmd: '"..cmd.."'): \n"..utils.dump(rv))
 	end
 end
 
@@ -147,7 +149,7 @@ function reconf.apnet_rm(dirtyList)
 	uci:foreach('wireless', 'wifi-iface', function(s)
 		if s.ssid == wifi.getSubstitutedSsid(settings.get('network.ap.ssid')) then sname = s['.name']; return false end
 	end)
-	if sname == nil then return log:info("AP network configuration does not exist, nothing to remove") end
+	if sname == nil then return log:info(MOD_ABBR, "AP network configuration does not exist, nothing to remove") end
 	uci:delete('wireless', sname)
 	reloadBit(dirtyList, 'network'); commitBit(dirtyList, 'wireless')
 end
@@ -212,15 +214,15 @@ end
 function reconf.dnsredir_add(dirtyList)
 	local redirText = '/#/' .. settings.get('network.ap.address')
 	local sname = utils.getUciSectionName('dhcp', 'dnsmasq')
-	if sname == nil then return log:error("dhcp config does not contain a dnsmasq section") end
+	if sname == nil then return log:error(MOD_ABBR, "dhcp config does not contain a dnsmasq section") end
-	if uci:get('dhcp', sname, 'address') ~= nil then return log:debug("DNS address redirection already in place, not re-adding", false) end
+	if uci:get('dhcp', sname, 'address') ~= nil then return log:info(MOD_ABBR, "DNS address redirection already in place, not re-adding", false) end
 
 	uci:set('dhcp', sname, 'address', {redirText})
 	commitBit(dirtyList, 'dhcp'); reloadBit(dirtyList, 'dnsmasq')
 end
 function reconf.dnsredir_rm(dirtyList)
 	local sname = utils.getUciSectionName('dhcp', 'dnsmasq')
-	if sname == nil then return log:error("dhcp config does not contain a dnsmasq section") end
+	if sname == nil then return log:error(MOD_ABBR, "dhcp config does not contain a dnsmasq section") end
 
 	uci:delete('dhcp', sname, 'address')
 	commitBit(dirtyList, 'dhcp'); reloadBit(dirtyList, 'dnsmasq')
@@ -230,21 +232,21 @@ end
 --TODO: handle os.rename() return values (nil+msg on error)
 function reconf.wwwcaptive_add(dirtyList)
 	if utils.exists(M.WWW_CAPTIVE_INDICATOR) then
-		return log:debug("WWW captive directory already in place, not redoing", false)
+		return log:info(MOD_ABBR, "WWW captive directory already in place, not redoing", false)
 	end
 	local rv,reason = os.rename('/www', M.WWW_RENAME_NAME)
 	if rv == true then
 		utils.symlink(M.WWW_CAPTIVE_PATH, '/www')
 		return true
 	else
-		return log:error("Could not rename /www to " .. M.WWW_RENAME_NAME .. "(" .. reason .. ")")
+		return log:error(MOD_ABBR, "Could not rename /www to " .. M.WWW_RENAME_NAME .. "(" .. reason .. ")")
 	end
 end
 function reconf.wwwcaptive_rm(dirtyList)
-	if not utils.exists(M.WWW_CAPTIVE_INDICATOR) then return log:debug("WWW captive directory not in place, not undoing", false) end
+	if not utils.exists(M.WWW_CAPTIVE_INDICATOR) then return log:info(MOD_ABBR, "WWW captive directory not in place, not undoing", false) end
 	os.remove('/www')
 	if os.rename(M.WWW_RENAME_NAME, '/www') ~= true then
-		return log:error("Could not rename " .. M.WWW_RENAME_NAME .. " to /www")
+		return log:error(MOD_ABBR, "Could not rename " .. M.WWW_RENAME_NAME .. " to /www")
 	end
 	return true
 end
@@ -286,21 +288,23 @@ function M.setupAccessPoint(ssid)
 	M.setStatus(M.CREATED,"Access point created");
 
 	local ds = wifi.getDeviceState()
-	--log:info("  network/status: ")
+	--log:info(MOD_ABBR, "  network/status: ")
-	log:info("    ssid: ".. utils.dump(ds.ssid))
+	log:info(MOD_ABBR, "    ssid: ".. utils.dump(ds.ssid))
-	--[[log:info("    bssid: ".. utils.dump(ds.bssid))
+	--[[
-	log:info("    channel: ".. utils.dump(ds.channel))
+	log:info(MOD_ABBR, "    bssid: ".. utils.dump(ds.bssid))
-	log:info("    mode: ".. utils.dump(ds.mode))
+	log:info(MOD_ABBR, "    channel: ".. utils.dump(ds.channel))
-	log:info("    encryption: ".. utils.dump(ds.encryption))
+	log:info(MOD_ABBR, "    mode: ".. utils.dump(ds.mode))
-	log:info("    quality: ".. utils.dump(ds.quality))
+	log:info(MOD_ABBR, "    encryption: ".. utils.dump(ds.encryption))
-	log:info("    quality_max: ".. utils.dump(ds.quality_max))
+	log:info(MOD_ABBR, "    quality: ".. utils.dump(ds.quality))
-	log:info("    txpower: ".. utils.dump(ds.txpower))
+	log:info(MOD_ABBR, "    quality_max: ".. utils.dump(ds.quality_max))
-	log:info("    signal: ".. utils.dump(ds.signal))
+	log:info(MOD_ABBR, "    txpower: ".. utils.dump(ds.txpower))
-	log:info("    noise: ".. utils.dump(ds.noise))
+	log:info(MOD_ABBR, "    signal: ".. utils.dump(ds.signal))
-	log:info("    raw: ".. utils.dump(ds))
+	log:info(MOD_ABBR, "    noise: ".. utils.dump(ds.noise))
+	log:info(MOD_ABBR, "    raw: ".. utils.dump(ds))
 
 	local localip = wifi.getLocalIP()
-	log:info("    localip: "..utils.dump(localip))]]--
+	log:info(MOD_ABBR, "    localip: "..utils.dump(localip))
+	--]]
 
 	return true
 end
@@ -311,13 +315,13 @@ end
 -- @tparam string ssid The SSID to use for the access point.
 -- @return True on success or nil+msg on error.
 function M.enableAccessPoint(ssid)
-	log:debug("enableAccessPoint ssid: ".. utils.dump(ssid))
+	log:info(MOD_ABBR, "enableAccessPoint ssid: ".. utils.dump(ssid))
 
 	M.switchConfiguration{apnet="add_noreload"}
 	wifi.activateConfig(ssid)
 
 	local ds = wifi.getDeviceState()
-	log:debug("    ssid: ".. utils.dump(ds.ssid))
+	log:info(MOD_ABBR, "    deviceState.ssid: ".. utils.dump(ds.ssid))
 
 	return true
 end
@@ -330,7 +334,7 @@ end
 -- @tparam boolean recreate If true, a new UCI configuration based on scan data will always be created, otherwise an attempt will be made to use an existing configuration.
 -- @return True on success or nil+msg on error.
 function M.associateSsid(ssid, passphrase, recreate)
-	log:info("netconfig:associateSsid: "..(ssid or "<nil>")..", "..(recreate or "<nil>"))
+	log:info(MOD_ABBR, "netconfig:associateSsid: "..(ssid or "<nil>")..", "..(recreate or "<nil>"))
 	M.setStatus(M.CONNECTING,"Connecting...");
 
 	-- see if previously configured network for given ssid exists
@@ -374,7 +378,7 @@ function M.associateSsid(ssid, passphrase, recreate)
 	local nextAttemptTime = os.time()
 	while true do
 		if os.time() > nextAttemptTime then
-			log:debug("associated check "..utils.dump(attempt).."/"..utils.dump(maxAttempts))
+			log:verbose(MOD_ABBR, "associated check "..utils.dump(attempt).."/"..utils.dump(maxAttempts))
 			if wifi.getLocalIP() ~= nil and wifi.getDeviceState().ssid == ssid then
 				break
 			else
@@ -390,13 +394,14 @@ function M.associateSsid(ssid, passphrase, recreate)
 			end
 		end
 	end
+	log:info(MOD_ABBR, "Network associated")
 
 	-- signin to connect.doodle3d.com
 	local success, output = signin.signin()
 	if success then
-  		log:info("Signed in")
+  		log:info(MOD_ABBR, "Signed in")
 	else
-		log:info("Signing in failed")
+		log:info(MOD_ABBR, "Signing in failed")
 	end
 
 	-- report we are connected after signin attempt
@@ -404,6 +409,7 @@ function M.associateSsid(ssid, passphrase, recreate)
 
 	return true
 end
+
 --- Disassociate wlan device as client from all SSID's.
 -- Note: this function might belong in the wlanconfig module but that would introduce
 -- a circular dependency, easiest solution is to place the function here.
@@ -417,24 +423,22 @@ function M.disassociate()
 end
 
 function M.getStatus()
-	log:info("network:getStatus")
+	log:verbose(MOD_ABBR, "network:getStatus")
 	local file, error = io.open('/tmp/networkstatus.txt','r')
 	if file == nil then
-		--log:error("Util:Access:Can't read controller file. Error: "..error)
+		--log:error(MOD_ABBR, "Util:Access:Can't read controller file. Error: "..error)
 		return "",""
 	else
 		local status = file:read('*a')
-		--log:info("  status: "..utils.dump(status))
 		file:close()
 		local code, msg = string.match(status, '([^|]+)|+(.*)')
-		--log:info("  code: "..utils.dump(code))
+		log:verbose(MOD_ABBR, "  raw status: "..utils.dump(status).." (code: "..utils.dump(code)..", msg: "..utils.dump(msg)..")")
-		--log:info("  msg: "..utils.dump(msg))
 		return code,msg
 	end
 end
 
 function M.setStatus(code,msg)
-	log:info("network:setStatus: "..code.." | "..msg)
+	log:info(MOD_ABBR, "network:setStatus: "..code.." | "..msg)
 	local file = io.open('/tmp/networkstatus.txt','w')
 	file:write(code.."|"..msg)
 	file:flush()

src/network/signin.lua

@@ -20,6 +20,7 @@ local status = require('util.status')
 local M = {}
 
 local STATUS_FILE = "signinstatus"
+local MOD_ABBR = "NTSI"
 
 local IDLE_STATUS 			= 1
 local SIGNING_IN_STATUS 	= 2
@@ -27,15 +28,21 @@ local SIGNING_IN_STATUS 	= 2
 --- Signin to connect.doodle3d.com server
 --
 function M.signin()
-
+	log:verbose(MOD_ABBR, "signin:signin");
-	--log:debug("signin:signin");
 
 	local code, msg = M.getStatus()
-	--log:debug("  status: "..utils.dump(code).." "..utils.dump(msg));
+	--log:verbose(MOD_ABBR, "  status: "..utils.dump(code).." "..utils.dump(msg));
 
 	-- if we are already signin in, skip
 	if(code == SIGNING_IN_STATUS) then
-		log:debug("  skipping signin")
+		log:verbose(MOD_ABBR, "  already signing in, skipping")
+		return
+	end
+
+	local ds = wifi.getDeviceState()
+	log:verbose(MOD_ABBR, "  wifi deviceState.mode: "..utils.dump(ds.mode))
+	if ds.mode ~= "sta" then
+		log:verbose(MOD_ABBR, "  wifi not in station mode, skipping signin")
 		return
 	end
 
@@ -53,10 +60,10 @@ function M.signin()
 	local signinResponse = ""
 	while true do
 		if os.time() > nextAttemptTime then
-			log:debug("signin attempt "..utils.dump(attempt).."/"..utils.dump(maxAttempts))
+			log:verbose(MOD_ABBR, "  signin attempt "..utils.dump(attempt).."/"..utils.dump(maxAttempts))
 			local signedin = false
 			local localip = wifi.getLocalIP();
-			--log:debug("  localip: "..utils.dump(localip))
+			--log:verbose(MOD_ABBR, "  localip: "..utils.dump(localip))
 			if localip ~= nil then
 
 				local wifiboxid = wifi.getSubstitutedSsid(settings.get('network.cl.wifiboxid'))
@@ -64,16 +71,16 @@ function M.signin()
 
 				local cmd = "wget -q -T 2 -t 1 -O - "..baseurl.."?wifiboxid="..wifiboxid.."\\&localip="..localip;
 				signinResponse = utils.captureCommandOutput(cmd);
-				log:debug("  signin response: \n"..utils.dump(signinResponse))
+				log:verbose(MOD_ABBR, "  signin response: \n"..utils.dump(signinResponse))
 				local success = signinResponse:match('"status":"success"')
-				log:debug("  success: "..utils.dump(success))
+				log:verbose(MOD_ABBR, "  success: "..utils.dump(success))
 				if success ~= nil then
 					signedin = true
 				else
-					log:warn("signin failed request failed (response: "..utils.dump(signinResponse)..")")
+					log:warning(MOD_ABBR, "signin failed, request failed (response: "..utils.dump(signinResponse)..")")
 				end
 			else
-				log:warn("signin failed no local ip found (attempt: "..utils.dump(attempt).."/"..utils.dump(maxAttempts)..")")
+				log:warning(MOD_ABBR, "signin failed, no local ip found (attempt: "..utils.dump(attempt).."/"..utils.dump(maxAttempts)..")")
 			end
 
 			if signedin then
@@ -100,7 +107,7 @@ function M.getStatus()
 end
 
 function M.setStatus(code,msg)
-	log:info("signin:setStatus: "..code.." | "..msg)
+	log:verbose(MOD_ABBR, "signin:setStatus: " .. code .. " (" .. msg .. ")")
 	status.set(STATUS_FILE,code,msg);
 end
 

src/network/wlanconfig.lua

@@ -13,6 +13,8 @@ local iwinfo = require('iwinfo')
 
 local M = {}
 
+local MOD_ABBR = "NTWL"
+
 -- NOTE: fallback device 'radio0' is required because sometimes the wlan0 device disappears
 M.DFL_DEVICE = 'wlan0'
 M.DFL_DEVICE_FALLBACK = 'radio0'
@@ -25,12 +27,12 @@ local deviceName, deviceApi
 local cachedApSsid, baseApSsid = nil, nil
 
 function M.getSubstitutedSsid(unformattedSsid)
-	log:debug("getSubstitutedSsid unformattedSsid:'" .. (unformattedSsid or "nil") .. "' baseApSsid:'" .. (baseApSsid or "nil") .. "' cachedApSsid:'" .. (cachedApSsid or "nil"))
+	log:verbose(MOD_ABBR, "getSubstitutedSsid unformattedSsid:'" .. (unformattedSsid or "nil") .. "' baseApSsid:'" .. (baseApSsid or "nil") .. "' cachedApSsid:'" .. (cachedApSsid or "nil"))
 	if unformattedSsid == baseApSsid and cachedApSsid ~= nil then return cachedApSsid end
 	if not unformattedSsid or type(unformattedSsid) ~= 'string' then return nil end
 
 	local macTail = M.getMacAddress():sub(7)
-	log:debug("  macTail:'" .. macTail)
+	log:verbose(MOD_ABBR, "  macTail:'" .. macTail)
 	baseApSsid = unformattedSsid
 	cachedApSsid = unformattedSsid:gsub('%%%%MAC_ADDR_TAIL%%%%', macTail)
 	return cachedApSsid
@@ -75,7 +77,7 @@ function M.init(device)
 		deviceName = M.DFL_DEVICE_FALLBACK
 		deviceApi = iwinfo.type(deviceName)
 
-		log:info("wireless device '" .. devInitial .. "' not found, trying fallback '" .. deviceName .. "'")
+		log:info(MOD_ABBR, "wireless device '" .. devInitial .. "' not found, trying fallback '" .. deviceName .. "'")
 
 		if not deviceApi then
 			return false, "No such wireless device: '" .. devInitial .. "' (and fallback '" .. deviceName .. "' does not exist either)"
@@ -107,9 +109,9 @@ end
 --returns the wireless device's MAC address (as string, without colons)
 --(lua numbers on openWrt seem to be 32bit so they cannot represent a MAC address as one number)
 function M.getMacAddress()
-	log:debug("getMacAddress")
+	log:verbose(MOD_ABBR, "getMacAddress")
 	local macText = utils.readFile('/sys/class/net/' .. deviceName .. '/address')
-	log:debug("  macText: '" .. (macText or "nil") .. "'")
+	log:verbose(MOD_ABBR, "  macText: '" .. (macText or "nil") .. "'")
 	local out = ''
 
 	-- Hack to prevent failure in case the MAC address could not be obtained.
@@ -126,9 +128,10 @@ end
 --returns the wireless local ip address
 function M.getLocalIP()
 	local ifconfig, rv = utils.captureCommandOutput("ifconfig wlan0");
-	--log:debug("  ifconfig: \n"..utils.dump(ifconfig));
+	log:bulk(MOD_ABBR, "  ifconfig: \n"..utils.dump(ifconfig));
-	local localip = ifconfig:match('inet addr:([%d\.]+)')
+
-	return localip;
+	local localip = ifconfig:match('inet addr:([%d%.]+)')
+	return localip
 end
 
 function M.getDeviceName()
@@ -140,9 +143,9 @@ end
 -- @return data for all or requested network; false+error on failure or nil when requested network not found
 function M.getScanInfo(ssid)
 	local iw = iwinfo[deviceApi]
-	log:info("start wifi scan")
+	log:info(MOD_ABBR, "start wifi scan")
 	local sr = iw.scanlist(deviceName)
-	log:info("wifi scan done")
+	log:info(MOD_ABBR, "wifi scan done")
 	local si, se
 
 	if ssid == nil then
@@ -186,12 +189,12 @@ end
 --- Activate wireless section for given SSID and disable all others
 -- @param ssid	SSID of config to enable, or nil to disable all network configs
 function M.activateConfig(ssid)
-	--log:info("wlanconfig.activateConfig: "..ssid);
+	log:verbose(MOD_ABBR, "wlanconfig.activateConfig: "..ssid);
 
 	-- make sure only one is enabled
 	uci:foreach('wireless', 'wifi-iface', function(s)
 		local disabled = s.ssid ~= ssid and '1' or '0'
-		--log:info("    "..utils.dump(s.ssid).." disable: "..utils.dump(disabled))
+		log:verbose(MOD_ABBR, "  ssid: "..utils.dump(s.ssid).." disabled: "..utils.dump(disabled))
 		uci:set('wireless', s['.name'], 'disabled', disabled)
 	end)
 
@@ -209,11 +212,14 @@ function M.activateConfig(ssid)
 			return false
 		end
 	end)
-	--[[log:info("  result:");
+
+	--[[
+	log:verbose(MOD_ABBR, "  wifi reorder result:");
 	uci:foreach('wireless', 'wifi-iface', function(s)
 		local disabled = s.ssid ~= ssid and '1' or '0'
-		log:info("    "..utils.dump(s.ssid).." disable: "..utils.dump(disabled))
+		log:verbose(MOD_ABBR, "    ssid: "..utils.dump(s.ssid).." disabled: "..utils.dump(disabled))
-	end)]]--
+	end)
+	--]]
 
 	uci:commit('wireless')
 end
@@ -241,7 +247,7 @@ function M.createConfigFromScanInfo(info, passphrase, disabled)
 	uci:foreach('wireless', 'wifi-iface', function(s)
 		--if s.bssid == info.bssid then
 		if s.ssid == info.ssid then
-			log:debug("removing old wireless config for net '" .. s.ssid .. "'")
+			log:verbose(MOD_ABBR, "removing old wireless config for net '" .. s.ssid .. "'")
 			uci:delete('wireless', s['.name'])
 --			return false --keep looking, just in case multiple entries with this bssid exist
 		end

src/rest/api/api_config.lua

@@ -15,6 +15,8 @@ local wifi = require('network.wlanconfig')
 local accessManager = require('util.access')
 local printerAPI = require('rest.api.api_printer')
 
+local MOD_ABBR = "ACFG"
+
 local M = {
 	isApi = true
 }
@@ -57,7 +59,7 @@ end
 -- returns substituted_wifiboxid (since version 0.10.2)
 -- returns substituted_ssid (since version 0.9.1)
 function M._global_POST(request, response)
-	--log:info("API:config:set")
+	log:verbose(MOD_ABBR, "API:config(set)")
 
 	if not operationsAccessOrFail(request, response) then return end
 
@@ -65,14 +67,14 @@ function M._global_POST(request, response)
 
 	local validation = {}
 	for k,v in pairs(request:getAll()) do
-		--log:info("  "..k..": "..v);
+		log:verbose(MOD_ABBR, "  about to set '"..k.."' -> '"..v.."'");
 		local r,m = settings.set(k, v, true)
 
 		if r then
 			validation[k] = "ok"
 		elseif r == false then
 			validation[k] = "could not save setting ('" .. m .. "')"
-			log:info("  m: "..utils.dump(m))
+			log:info(MOD_ABBR, "  failed to set '"..k.."' ("..utils.dump(m)..")")
 		elseif r == nil then
 			settings.commit()
 			response:setError(m)
@@ -109,18 +111,20 @@ end
 -- and printer.type is set to 'ultimaker' then
 -- only the printer.startcode under the ultimaker subsection is removed.
 function M.reset_POST(request, response)
-	--log:info("API:reset");
+	--log:verbose(MOD_ABBR, "API:config/reset")
 	if not operationsAccessOrFail(request, response) then return end
 	response:setSuccess()
 
 	for k,v in pairs(request:getAll()) do
-		--log:info("  "..k..": "..v);
+		--log:info(MOD_ABBR, "  "..k..": "..v);
 		local r,m = settings.reset(k);
 		if r ~= nil then
 			response:addData(k, "ok")
+			log:verbose(MOD_ABBR, "  reset " .. k)
 		else
 			response:addData(k, "could not reset key ('" .. m .. "')")
 			response:setError(m)
+			log:verbose(MOD_ABBR, "  could not reset key " .. k .. "(" .. m .. ")")
 			return
 		end
 	end

src/rest/api/api_info.lua

@@ -16,11 +16,19 @@ local printerAPI = require('rest.api.api_printer')
 local wifi = require('network.wlanconfig')
 local settings = require('util.settings')
 
+local MOD_ABBR = "AINF"
+
 local TMP_DIR = '/tmp'
 local LOG_COLLECT_DIRNAME = 'wifibox-logs'
 local LOG_COLLECT_DIR = TMP_DIR .. '/' .. LOG_COLLECT_DIRNAME
-local WIFIBOX_LOG_FILENAME = 'wifibox.log'
+local DEFAULT_WIFIBOX_LOG_FILENAME = 'wifibox.log'
-local WIFIBOX_LOG_FILE = TMP_DIR .. '/' .. WIFIBOX_LOG_FILENAME
+local DEFAULT_WIFIBOX_LOG_FILE = TMP_DIR .. '/' .. DEFAULT_WIFIBOX_LOG_FILENAME
+local WIFIBOX_STDOUT_LOG_FILENAME = 'wifibox.stdout.log'
+local WIFIBOX_STDOUT_LOG_FILE = TMP_DIR .. '/' .. WIFIBOX_STDOUT_LOG_FILENAME
+local WIFIBOX_VERSION_FILENAME = 'wifibox-version'
+local WIFIBOX_VERSION_FILE = '/etc/' .. WIFIBOX_VERSION_FILENAME
+local ROTATED_LOGS_DIRNAME = 'wifibox-rotated'
+local ROTATED_LOGS_DIR = TMP_DIR .. '/' .. ROTATED_LOGS_DIRNAME
 
 local SYSLOG_FILENAME = 'syslog'
 local PROCESS_LIST_FILENAME = 'processes'
@@ -34,7 +42,7 @@ local USB_DIRTREE_COMMAND = "ls -R /sys/devices/platform/ehci-platform/usb1 | gr
 local USB_DIRTREE_FILENAME = 'sys_devices_platform_ehci-platform_usb1.tree'
 
 local PRINT3D_BASEPATH = '/tmp'
-local PRINT3D_LOG_FILENAME_PREFIX = 'print3d-'
+local PRINT3D_LOG_FILENAME_PREFIX = 'print3d.'
 local PRINT3D_LOG_FILENAME_SUFFIX = '.log'
 local LOG_COLLECT_ARCHIVE_FILENAME = LOG_COLLECT_DIRNAME .. '.tgz'
 local LOG_COLLECT_ARCHIVE_FILE = TMP_DIR .. '/' .. LOG_COLLECT_ARCHIVE_FILENAME
@@ -63,11 +71,34 @@ function M.logfiles(request, response)
 	rv,msg = lfs.mkdir(LOG_COLLECT_DIR)
 	rv,msg = lfs.chdir(TMP_DIR)
 
+	local wifiboxLogFilePath = log:getLogFilePath()
+	local wifiboxLogFileName = wifiboxLogFilePath and wifiboxLogFilePath:match('.*/(.*)')
+
 
 	--[[ create temporary files ]]--
 
-	-- copy wifibox API-script log
+	-- copy wifibox API-script (firmware) log
-	rv,sig,code = redirectedExecute('cp ' .. WIFIBOX_LOG_FILE .. ' ' .. LOG_COLLECT_DIR)
+	lfs.link(wifiboxLogFilePath, LOG_COLLECT_DIR .. '/' .. wifiboxLogFileName)
+
+	-- copy d3dapi script stdout/stderr (fallback) log
+	lfs.link(WIFIBOX_STDOUT_LOG_FILE, LOG_COLLECT_DIR .. '/' .. WIFIBOX_STDOUT_LOG_FILENAME)
+
+	-- collect and copy print3d server logs
+	for file in lfs.dir(PRINT3D_BASEPATH) do
+		if file:find(PRINT3D_LOG_FILENAME_PREFIX) == 1 and file:find(PRINT3D_LOG_FILENAME_SUFFIX) ~= nil then
+			local srcLogFile = PRINT3D_BASEPATH .. '/' .. file
+			local tgtLogFile = LOG_COLLECT_DIR .. '/' .. file
+			lfs.link(srcLogFile, tgtLogFile)
+		end
+	end
+
+	-- copy rotated firmware and print3d logs
+	rv,msg = lfs.mkdir(LOG_COLLECT_DIR .. '/' .. ROTATED_LOGS_DIRNAME)
+	for file in lfs.dir(ROTATED_LOGS_DIR) do
+		local srcLogFile = ROTATED_LOGS_DIR .. '/' .. file
+		local tgtLogFile = LOG_COLLECT_DIR .. '/' .. ROTATED_LOGS_DIRNAME .. '/' .. file
+		lfs.link(srcLogFile, tgtLogFile)
+	end
 
 	-- capture syslog
 	rv,sig,code = os.execute('logread > ' .. LOG_COLLECT_DIR .. '/' .. SYSLOG_FILENAME)
@@ -87,7 +118,10 @@ function M.logfiles(request, response)
 	-- list directory structure for primary USB controller
 	rv,sig,code = os.execute(USB_DIRTREE_COMMAND .. ' > ' .. LOG_COLLECT_DIR .. '/' .. USB_DIRTREE_FILENAME)
 
+	rv,sig,code = redirectedExecute('cp ' .. WIFIBOX_VERSION_FILE .. ' ' .. LOG_COLLECT_DIR)
+
 	-- copy relevant openwrt configuration files
+	-- Note: we cannot link them because that would require the link to span over filesystems
 	rv,msg = lfs.mkdir(LOG_COLLECT_DIR .. '/config')
 	for _,v in pairs(UCI_CONFIG_FILES_TO_SAVE) do
 		local srcFile = '/etc/config/' .. v
@@ -95,19 +129,12 @@ function M.logfiles(request, response)
 		if v ~= 'wireless' then
 			rv,sig,code = redirectedExecute('cp ' .. srcFile .. ' ' .. tgtFile)
 		else
+			-- replace WiFi passwords with '...'
 			rv,sig,code = os.execute("sed \"s/option key '.*'/option key '...'/g\" " .. srcFile .. " > " .. tgtFile)
 		end
 	end
 
-	-- collect and copy print3d server logs
+	-- create tar.gz archive of the files/data we collected
-	for file in lfs.dir(PRINT3D_BASEPATH) do
-		if file:find(PRINT3D_LOG_FILENAME_PREFIX) == 1 and file:find(PRINT3D_LOG_FILENAME_SUFFIX) ~= nil then
-			local srcLogFile = PRINT3D_BASEPATH .. '/' .. file
-			local tgtLogFile = LOG_COLLECT_DIR .. '/' .. file
-			rv,sig,code = redirectedExecute('cp ' .. srcLogFile .. ' ' .. tgtLogFile)
-			end
-		end
-
 	rv,sig,code = redirectedExecute('tar czf ' .. LOG_COLLECT_ARCHIVE_FILE .. ' ' .. LOG_COLLECT_DIRNAME) --returns 0 success, 1 error
 
 
@@ -133,13 +160,19 @@ function M.logfiles(request, response)
 	rv,sig,code = redirectedExecute('rm ' .. LOG_COLLECT_DIR .. '/config/*')
 	rv,msg = lfs.rmdir(LOG_COLLECT_DIR .. '/config')
 
+	-- Note: this assumes the rotated logs directory does not contain subdirectories
+	rv,sig,code = redirectedExecute('rm ' .. LOG_COLLECT_DIR .. '/' .. ROTATED_LOGS_DIRNAME .. '/*')
+	rv,msg = lfs.rmdir(LOG_COLLECT_DIR .. '/' .. ROTATED_LOGS_DIRNAME)
+
+	rv,sig,code = redirectedExecute('rm ' .. LOG_COLLECT_DIR .. '/' .. WIFIBOX_VERSION_FILENAME)
 	rv,sig,code = redirectedExecute('rm ' .. LOG_COLLECT_DIR .. '/' .. USB_DIRTREE_FILENAME)
 	rv,sig,code = redirectedExecute('rm ' .. LOG_COLLECT_DIR .. '/' .. DISKFREE_FILENAME)
 	rv,sig,code = redirectedExecute('rm ' .. LOG_COLLECT_DIR .. '/' .. MOUNTS_FILENAME)
 	rv,sig,code = redirectedExecute('rm ' .. LOG_COLLECT_DIR .. '/' .. MEMINFO_FILENAME)
 	rv,sig,code = redirectedExecute('rm ' .. LOG_COLLECT_DIR .. '/' .. PROCESS_LIST_FILENAME)
 	rv,sig,code = redirectedExecute('rm ' .. LOG_COLLECT_DIR .. '/' .. SYSLOG_FILENAME)
-	rv,sig,code = redirectedExecute('rm ' .. LOG_COLLECT_DIR .. '/' .. WIFIBOX_LOG_FILENAME)
+	rv,sig,code = redirectedExecute('rm ' .. LOG_COLLECT_DIR .. '/' .. WIFIBOX_STDOUT_LOG_FILENAME)
+	rv,sig,code = redirectedExecute('rm ' .. LOG_COLLECT_DIR .. '/' .. wifiboxLogFileName)
 
 	rv,msg = lfs.rmdir(LOG_COLLECT_DIR)
 
@@ -147,16 +180,16 @@ function M.logfiles(request, response)
 end
 
 function M.access(request, response)
-	--log:info("  remoteAddress: |"..utils.dump(request.remoteAddress).."|");
+	--log:info(MOD_ABBR, "  remoteAddress: |"..utils.dump(request.remoteAddress).."|");
-	--log:info("  controller: |"..utils.dump(accessManager.getController()).."|");
+	--log:info(MOD_ABBR, "  controller: |"..utils.dump(accessManager.getController()).."|");
 
 	local hasControl = accessManager.hasControl(request.remoteAddress)
-	-- if hasControl then log:info("  hasControl: true")
+	-- if hasControl then log:info(MOD_ABBR, "  hasControl: true")
-	-- else log:info("  hasControl: false") end
+	-- else log:info(MOD_ABBR, "  hasControl: false") end
 	response:setSuccess()
 	response:addData('has_control', hasControl)
 
-	return true
+	return
 end
 
 function M.status(request, response)

src/rest/api/api_network.lua

@@ -16,6 +16,8 @@ local signin = require('network.signin')
 local accessManager = require('util.access')
 local printerAPI = require('rest.api.api_printer')
 
+local MOD_ABBR = "ANET"
+
 local M = {
 	isApi = true
 }
@@ -149,9 +151,9 @@ function M.associate_POST(request, response)
 
 	local rv,msg = netconf.associateSsid(argSsid, argPhrase, argRecreate)
 	if rv then
-		log:info("associated to wifi: "..utils.dump(argSsid))
+		log:info(MOD_ABBR, "associated to wifi: "..utils.dump(argSsid))
 	else
-		log:info("failed to associate to wifi: "..utils.dump(argSsid).." ("..utils.dump(msg)..")")
+		log:info(MOD_ABBR, "failed to associate to wifi: "..utils.dump(argSsid).." ("..utils.dump(msg)..")")
 	end
 
 end
@@ -201,14 +203,13 @@ function M.remove_POST(request, response)
 end
 
 function M.signin(request, response)
-	log:info("API:Network:signin")
 	local success, output = signin.signin()
 	if success then
-  		log:info("API:Network:signed in")
+  		log:info(MOD_ABBR, "signed in")
   		response:setSuccess("API:Network:signed in")
   		response:addData("response", output)
 	else
-		log:info("API:Network:Signing in failed")
+		log:warning(MOD_ABBR, "signing in failed")
 		response:setError("Signing in failed")
 	end
 end

src/rest/api/api_printer.lua

@@ -5,15 +5,17 @@
 -- @license This software is licensed under the terms of the GNU GPL v2 or later.
 -- See file LICENSE.txt or visit http://www.gnu.org/licenses/gpl.html for full license details.
 
+-- TODO: return errors like in print_POST (error message in a 'msg' key instead of directly in the response) if this does not break API compatibility
 
 local lfs = require('lfs')
 local log = require('util.logger')
 local utils = require('util.utils')
 local settings = require('util.settings')
-local printDriver = require('print3d')
 local printerUtils = require('util.printer')
 local accessManager = require('util.access')
 
+local MOD_ABBR = "APRN"
+
 local M = {
 	isApi = true
 }
@@ -27,7 +29,7 @@ end
 function M.temperature(request, response)
 	local argId = request:get("id")
 	local printer,msg = printerUtils.createPrinterOrFail(argId, response)
-	if not printer or not printer:hasSocket() then return false end
+	if not printer or not printer:hasSocket() then return end
 
 	local temperatures,msg = printer:getTemperatures()
 
@@ -38,21 +40,21 @@ function M.temperature(request, response)
 		response:addData('hotend_target', temperatures.hotend_target)
 		response:addData('bed', temperatures.bed)
 		response:addData('bed_target', temperatures.bed_target)
+	elseif temperatures == false then
+		response:addData('status', msg)
+		response:setFail("could not get temperature information (" .. msg .. ")")
 	else
 		response:setError(msg)
-		return false;
 	end
-
-	return true;
 end
 
 function M.progress(request, response)
 	local argId = request:get("id")
 	local printer,msg = printerUtils.createPrinterOrFail(argId, response)
-	if not printer or not printer:hasSocket() then return false end
+	if not printer or not printer:hasSocket() then return end
 
 	-- NOTE: despite their names, `currentLine` is still the error indicator and `bufferedLines` the message in such case.
-	local currentLine,bufferedLines,totalLines = printer:getProgress()
+	local currentLine,bufferedLines,totalLines,bufferSize,maxBufferSize,seqNumber,seqTotal = printer:getProgress()
 
 	response:addData('id', argId)
 	if currentLine then
@@ -60,15 +62,20 @@ function M.progress(request, response)
 		response:addData('current_line', currentLine)
 		response:addData('buffered_lines', bufferedLines)
 		response:addData('total_lines', totalLines)
+		response:addData('buffer_size', bufferSize)
+		response:addData('max_buffer_size', maxBufferSize)
+		response:addData('seq_number', seqNumber)
+		response:addData('seq_total', seqTotal)
+	elseif progress == false then
+		response:addData('status', bufferedLines)
+		response:setFail("could not get progress information (" .. bufferedLines .. ")")
 	else
 		response:setError(bufferedLines)
-		return false
+	end
 end
 
-	return true;
+-- Note: onlyReturnState is optional and prevents response from being modified, used when calling from within other api call
-end
+-- Note: unlike regular API-functions, this one returns either true+state or false
-
--- NOTE: onlyReturnState is optional and prevents response from being modified
 function M.state(request, response, onlyReturnState)
 	local argId = request:get("id")
 	if not onlyReturnState then response:addData('id', argId) end
@@ -97,25 +104,24 @@ function M.state(request, response, onlyReturnState)
 				response:addData('state', rv)
 			end
 			return true, rv
-		else
+		else -- Note: do not differentiate between false and nil here, false should never be returned
 			if not onlyReturnState then response:setError(msg) end
 			return false
 		end
 	end
-	return true
+
+	--this point cannot be reached, no return necessary
 end
 
 -- retrieve a list of 3D printers currently supported
 function M.listall(request, response)
 	response:setSuccess()
 	response:addData('printers', printerUtils.supportedPrinters())
-	return true
 end
 
 
 
 function M.heatup_POST(request, response)
-
 	if not accessManager.hasControl(request.remoteAddress) then
 		response:setFail("No control access")
 		return
@@ -129,15 +135,17 @@ function M.heatup_POST(request, response)
 	local rv,msg = printer:heatup(temperature)
 
 	response:addData('id', argId)
-	if rv then response:setSuccess()
+	if rv then
-	else response:setFail(msg)
+		response:setSuccess()
+	elseif rv == false then
+		response:addData('status', msg)
+		response:setFail("could not start heatup (" .. msg .. ")")
+	else
+		response:setError(msg)
 	end
 end
 
 function M.stop_POST(request, response)
-
-	log:info("API:printer/stop")
-
 	if not accessManager.hasControl(request.remoteAddress) then
 		response:setFail("No control access")
 		return
@@ -146,7 +154,7 @@ function M.stop_POST(request, response)
 	local argId = request:get("id")
 	local argGcode = request:get("gcode")
 	local printer,msg = printerUtils.createPrinterOrFail(argId, response)
-	if not printer or not printer:hasSocket() then return false end
+	if not printer or not printer:hasSocket() then return end
 
 	if(argGcode == nil) then
 		argGcode = ""
@@ -154,15 +162,41 @@ function M.stop_POST(request, response)
 	local rv,msg = printer:stopPrint(argGcode)
 
 	response:addData('id', argId)
-	if rv then response:setSuccess()
+	if rv then
-	else response:setError(msg)
+		response:setSuccess()
+	elseif rv == false then
+		response:addData('status', msg)
+		response:setFail("could not stop print (" .. msg .. ")")
+	else
+		response:setError(msg)
 	end
 end
 
---accepts: first(bool) (chunks will be concatenated but output file will be cleared first if this argument is true)
+-- Used only in print_POST(); not nested for performance reasons
+local function addSequenceNumbering(printer, response)
+	-- NOTE: despite their names, `currentLine` is still the error indicator and `bufferedLines` the message in such case.
+	local currentLine,bufferedLines,totalLines,bufferSize,maxBufferSize,seqNumber,seqTotal = printer:getProgress()
+	if currentLine then
+		response:addData('seq_number', seqNumber)
+		response:addData('seq_total', seqTotal)
+	--else
+		--Note: getProgress failure is ignored (unlikely to happen if the other calls work, and also not really fatal here).
+		--      Alternatively, we could still add the fields with a special value (NaN is not supported by json, so perhaps -2?)
+	end
+end
+
+--requires: gcode(string) (the gcode to be appended)
+--accepts: id(string) (the printer ID to append to)
+--accepts: clear(bool) (chunks will be concatenated but output file will be cleared first if this argument is true)
+--accepts: first(deprecated) (an alias for 'clear')
 --accepts: start(bool) (only when this argument is true will printing be started)
+--accepts: total_lines(int) (the total number of lines that is going to be sent, will be used only for reporting progress)
+--accepts: seq_number(int) (sequence number of the chunk, must be given until clear() after given once, and incremented each time)
+--accepts: seq_total(int) (total number of gcode chunks to be appended, must be given until clear() after given once, and stay the same)
+--returns: when the gcode buffer cannot accept the gcode, or the IPC transaction fails,
+--         a fail with a (formal, i.e., parseable) status argument will be returned;
+--         additionally, current sequence number and total will be returned (both are -1 if they have not been set)
 function M.print_POST(request, response)
-
 	local controllerIP = accessManager.getController()
 	local hasControl = false
 	if controllerIP == "" then
@@ -172,7 +206,6 @@ function M.print_POST(request, response)
 		hasControl = true
 	end
 
-	log:info("  hasControl: "..utils.dump(hasControl))
 	if not hasControl then
 		response:setFail("No control access")
 		return
@@ -180,11 +213,18 @@ function M.print_POST(request, response)
 
 	local argId = request:get("id")
 	local argGcode = request:get("gcode")
-	local argIsFirst = utils.toboolean(request:get("first"))
+	local argClear = utils.toboolean(request:get("clear"))
+	local argIsFirst = utils.toboolean(request:get("first"))  -- deprecated
 	local argStart = utils.toboolean(request:get("start"))
+	local argTotalLines = request:get("total_lines") or -1
+	local argSeqNumber = request:get("seq_number") or -1
+	local argSeqTotal = request:get("seq_total") or -1
+	local remoteHost = request:getRemoteHost()
+	
+	log:info(MOD_ABBR, "print chunk metadata: total_lines=" .. argTotalLines .. ", seq_number=" .. argSeqNumber .. ", seq_total=" .. argSeqTotal)
 
 	local printer,msg = printerUtils.createPrinterOrFail(argId, response)
-	if not printer or not printer:hasSocket() then return false end
+	if not printer or not printer:hasSocket() then return end
 
 	response:addData('id', argId)
 
@@ -193,12 +233,15 @@ function M.print_POST(request, response)
 		return
 	end
 
-	if argIsFirst == true then
+	if argClear == true or argIsFirst == true then
-		log:debug("clearing all gcode for " .. printer:getId())
+		log:verbose(MOD_ABBR, "  clearing all gcode for " .. printer:getId())
 		response:addData('gcode_clear',true)
 		local rv,msg = printer:clearGcode()
 
-		if not rv then
+		if rv == false then
+			response:addData('status', msg)
+			response:setFail("could not clear gcode (" .. msg .. ")")
+		elseif rv == nil then
 			response:setError(msg)
 			return
 		end
@@ -206,14 +249,20 @@ function M.print_POST(request, response)
 
 	local rv,msg
 
-	-- TODO: return errors with a separate argument like here in the rest of the code (this is how we designed the API right?)
+	rv,msg = printer:appendGcode(argGcode, argTotalLines, { seq_number = argSeqNumber, seq_total = argSeqTotal, source = remoteHost })
-	rv,msg = printer:appendGcode(argGcode)
 	if rv then
+		addSequenceNumbering(printer, response)
 		--NOTE: this does not report the number of lines, but only the block which has just been added
 		response:addData('gcode_append',argGcode:len())
+	elseif rv == false then
+		addSequenceNumbering(printer, response)
+		response:addData('status', msg)
+		response:setFail("could not add gcode (" .. msg .. ")")
+		return
 	else
-		response:setError("could not add gcode")
+		addSequenceNumbering(printer, response)
 		response:addData('msg', msg)
+		response:setError("could not add gcode (" .. msg .. ")")
 		return
 	end
 
@@ -223,9 +272,14 @@ function M.print_POST(request, response)
 		if rv then
 			response:setSuccess()
 			response:addData('gcode_print',true)
+		elseif rv == false then
+			response:addData('status', msg)
+			response:setFail("could not send gcode (" .. msg .. ")")
+			return
 		else
-			response:setError("could not send gcode")
 			response:addData('msg', msg)
+			response:setError("could not send gcode (" .. msg .. ")")
+			return
 		end
 	else
 		response:setSuccess()

src/rest/api/api_sketch.lua

@@ -16,6 +16,8 @@ local lfs = require('lfs')
 local log = require('util.logger')
 local utils = require('util.utils')
 
+local MOD_ABBR = "ASKE"
+
 local M = {
 	isApi = true,
 	SKETCH_DIR = '/root/sketches',
@@ -29,7 +31,7 @@ local SKETCH_FILE_EXTENSION = 'svg'
 -- creates sketch directory, and sets response to error state on failure
 local function createSketchDirectory()
 	if os.execute('mkdir -p ' .. M.SKETCH_DIR) ~= 0 then
-		log:error("Error: could not create sketch directory '" .. M.SKETCH_DIR .. "'")
+		log:error(MOD_ABBR, "could not create sketch directory '" .. M.SKETCH_DIR .. "'")
 		response:setError("could not create sketch directory")
 		return false
 	end
@@ -133,7 +135,7 @@ function M._global_POST(request, response)
 	local sketchIdx = listSize > 0 and sketches[listSize] + 1 or 1
 	local sketchFile = M.SKETCH_DIR .. '/' .. constructSketchFilename(sketchIdx)
 
-	log:debug("saving sketch #" .. sketchIdx .. " (" .. argData:len() .. " bytes)")
+	log:verbose(MOD_ABBR, "saving sketch #" .. sketchIdx .. " (" .. argData:len() .. " bytes)")
 	local saveFile,msg = io.open(sketchFile, 'w')
 
 	if not saveFile then

src/rest/api/api_update.lua

@@ -10,6 +10,8 @@ local wifi = require('network.wlanconfig')
 local netconf = require('network.netconfig')
 local settings = require('util.settings')
 
+local MOD_ABBR = "AUPD"
+
 -- NOTE: the updater module 'detects' command-line invocation by existence of 'arg', so we have to make sure it is not defined.
 argStash = arg
 arg = nil
@@ -158,7 +160,7 @@ end
 function M.install_POST(request, response)
 	local argVersion = request:get("version")
 	local argNoRetain = request:get("no_retain")
-	log:info("API:update/install (noRetain: "..utils.dump(argNoRetain)..")")
+	log:info(MOD_ABBR, "API:update/install (noRetain: "..utils.dump(argNoRetain)..")")
 	local noRetain = argNoRetain == 'true'
 
 	if not operationsAccessOrFail(request, response) then return end

src/rest/request.lua

@@ -167,7 +167,8 @@ setmetatable(M, {
 })
 
 --This function initializes itself using various environment variables, the arg array and the given postData
---NOTE: if debugging is enabled, commandline arguments 'm' and 'f' override requested module and function
+--NOTE: if debugging is enabled, commandline argument 'p' (path) overrides requested module and function and
+--      'r' (rqType) overrides request method
 function M.new(environment, postData, debugEnabled)
 	local self = setmetatable({}, M)
 
@@ -180,6 +181,10 @@ function M.new(environment, postData, debugEnabled)
 		self.remoteAddress = environment['REMOTE_ADDR']
 	else
 		self.requestMethod = 'CMDLINE'
+		self.remoteHost = "cmdline"
+		self.remotePort = "0"
+		self.userAgent = "shell"
+		self.remoteAddress = "0.0.0.0"
 	end
 
 	self.cmdLineArgs = kvTableFromArray(arg)

src/rest/response.lua

@@ -20,6 +20,7 @@ local M = {}
 M.__index = M
 
 local REQUEST_ID_ARGUMENT = 'rq_id'
+local MOD_ABBR = "HRSP"
 
 M.httpStatusCode, M.httpStatusText, M.contentType = nil, nil, nil
 M.binaryData, M.binarySavename = nil, nil
@@ -129,9 +130,9 @@ function M:addPostResponseFunction(fn)
   table.insert(self.postResponseQueue, fn)
 end
 
---- Call all function on the post-response queue, see @{M:addPostResponseFunction} for details and a side-note.
+--- Call all functions on the post-response queue, see @{M:addPostResponseFunction} for details and a side-note.
 function M:executePostResponseQueue()
-  --log:info("Response:executePostResponseQueue: " .. utils.dump(self.postResponseQueue))
+	if #self.postResponseQueue > 0 then log:verbose(MOD_ABBR, "Response:executePostResponseQueue: " .. utils.dump(self.postResponseQueue)) end
 
 	for i,fn in ipairs(self.postResponseQueue) do fn() end
 end
@@ -152,7 +153,7 @@ function M:serializeAsJson()
 	return JSON:encode(self.body)
 end
 
---- Writes HTTP headers, followed by an HTTP body containing JSON data to stdout.
+--- Writes HTTP headers to stdout, followed by an HTTP body containing either JSON data or a file attachment.
 function M:send()
 	printHeaderLine("Status", self.httpStatusCode .. " " .. self.httpStatusText)
 	printHeaderLine("Content-Type", self.contentType)
@@ -169,7 +170,7 @@ function M:send()
 	end
 
 	if self.body.status ~= "success" then
-		log:debug("Response:"..utils.dump(self.body.status).." ("..utils.dump(self.body.msg)..")")
+		log:warning(MOD_ABBR, "Response status: "..utils.dump(self.body.status).." ("..utils.dump(self.body.msg)..")")
 	end
 end
 

src/script/README-loglite.md

@@ -0,0 +1,92 @@
+## Loglite
+
+The loglite script allows coloring and filtering of log files by specifying certain patterns and associating directives to them. These mainly specify colors but additionally, (non-)matched lines can be deleted from output and also all output lines can be numbered.
+
+
+### Usage
+
+The script can follow an existing log file (comparable to `tail -f`), or it can follow its standard input. A file to follow is always specified as the first argument and a filter set name as the second (use '-' as file name to read from standard input). Details on filter sets can be found below. If no filter set is mentioned on the command-line, the script will attempt to use one named 'default'.
+
+* Example following an existing log file using a filter set named 'example':   
+`./loglite.lua print3d.log example`.
+* Example using standard input, to filter/view a whole log file, with a filter set named 'serial' (note the '-' as file name):  
+`cat print3d-ttyACM0.log | ./loglite.lua - serial`
+* Example using standard input, to capture both output streams from `print3d`, with a filter set named 'example' (note the '-' as file name):  
+`./print3d -V 2>&1 | ./loglite.lua - example`.
+
+#### On WiFi-Box
+Loglite is already installed since version 0.10.10 as `loglite`.  
+Check `/root/.profile` for handy aliases like `tailfw` and `tailp3d`.
+
+### Filter sets
+
+The script looks for filter sets in the file '$HOME/loglite-filters.lua'. It looks like this:
+
+``` lua
+local M = {}
+
+M.default = {
+	['options'] = { mode = 'keep', count = 'none' },
+	['patterns'] = {
+		['%(error%)'] = 'red',
+		['%(warning%)'] = 'yellow',
+		['%(bulk%)'] = 'bold,black'
+	}
+}
+
+M.specialization = {
+	['parent'] = 'default',
+	['options'] = { mode = 'delete' }
+	['patterns'] = {
+		['setState%(%)'] = 'bblue,_nodelete'
+	}
+}
+
+return M
+```
+
+Here, the declaration and returning of `M` is required for the loglite script to be able to cleanly import the file. In `M.default`, 'default' is the name of a filter set being defined (similar for 'specialization'). Definitions can contain three so-called keys: 'parent' specifies a filter set to inherit from in order to reduce code duplication, 'options' and 'patterns' are described below.
+
+Inheritance can be used to set new keys or to override keys from the parent set. Previously set keys cannot be removed, but they can be set to a non-existing directive (e.g., Lua's 'false' keyword) to achieve the same effect. Note that directives in inheriting sets are currently not combined with previous ones, so for instance overriding `['test'] = 'red, _delete'` with `['test'] = 'blue'` will result in only the directive 'blue' to be applied.
+
+#### Options
+
+Two options are currently available:
+
+* `mode`, which specifies whether to keep log lines (`keep`, the default) or to drop them (`delete`). For specific lines this can then be overridden, see 'Patterns' below.
+* `count`, which can be set to `all` to prefix log lines with a counter, or `none` (default) to leave them as is.
+
+#### Patterns
+
+Pattern specifications are patterns as used in Lua: [Lua documentation on patterns](http://www.lua.org/pil/20.2.html).
+The following directives can be associated with a pattern:
+
+* A foreground color, one of: black, red, green, yellow, blue, magenta, cyan or white.
+* A background color, like foreground colors but prefixed with 'b'.
+* `bold`, which usually has the effect of rendering a bright variant of the foreground color (note that `bold,black` renders as dark gray).
+* `reverse` will reverse fore- and background colors.
+* Also available are `blink` and `underscore` but they do currently not work in all terminal programs or might need to be enabled in the preferences.
+* `_delete` or `_nodelete` to override the active mode specified in the 'options' above.
+
+Directives can be combined with ',' (e.g.: `'red,_nodelete'`). Finally, in any filter set, pattern rules are matched from top to bottom, the last one encountered overriding any previous conflicting directive.
+
+### Installation
+Note: Loglite is already installed on the WiFi-Box since version 0.10.10.
+
+Install Lua. See:  
+http://lua-users.org/wiki/LuaBinaries  
+It's tested in Lua 5.1 and Lua 5.2.
+
+Loglite will check for a `loglite-filters.lua` file in your home directory. It's recommended to create a symbolic link to the latest version.
+On OS X / Linux:
+```
+cd
+ln -s [absolute path to file]/loglite-filters.lua loglite-filters.lua
+```
+
+It's recommended to create a symbolic link in one of your PATH directories (`echo $PATH`) to the loglite.lua file. This allows you to run `loglite` from any directory.
+On OS X / Linux:
+```
+cd /usr/local/bin
+ln -s [absolute path to file]/loglite.lua loglite.lua
+```

src/script/d3d-updater.lua

@@ -24,6 +24,8 @@
 -- note: take care not to print any text in module functions, as this breaks http responses
 -- change representation of sysupgrade/factory info in versionInfo? (and also in image index?) <- create api call to get all info on all versions?
 
+local MOD_ABBR = "UPDA"
+
 local M = {}
 
 --- Possible states the updater can be in, they are stored in @{STATE_FILE}.
@@ -82,15 +84,15 @@ local baseUrl = M.DEFAULT_BASE_URL -- default, can be overwritten by M.setBaseUr
 -- @string msg The message to log.
 local function P(lvl, msg)
 	if log then
-		if lvl == -1 then log:debug(msg)
+		if lvl == -1 then log:verbose(MOD_ABBR, msg)
-		elseif lvl == 0 or lvl == 1 then log:info(msg)
+		elseif lvl == 0 or lvl == 1 then log:info(MOD_ABBR, msg)
 		end
 	else
 		if (-lvl <= verbosity) then print(msg) end
 	end
 end
 
---- Log a debug message, this function wraps @{P}.
+--- Log a debug/verbose message, this function wraps @{P}.
 -- The message will be logged with level -1 and be prefixed with '(DBG)'.
 -- @string msg The message to log.
 local function D(msg) P(-1, (log and msg or "(DBG) " .. msg)) end
@@ -99,7 +101,7 @@ local function D(msg) P(-1, (log and msg or "(DBG) " .. msg)) end
 -- Messages will be written to [stderr](http://www.cplusplus.com/reference/cstdio/stderr/), or logged using the logger set with @{setLogger}.
 -- @string msg The message to log.
 local function E(msg)
-	if log then log:error(msg)
+	if log then log:error(MOD_ABBR, msg)
 	else io.stderr:write(msg .. '\n')
 	end
 end
@@ -792,7 +794,7 @@ end
 -- @treturn bool|nil True on success (with the 'exception' as noted above) or nil on error.
 -- @treturn ?string|number (optional) Descriptive message or sysupgrade exit status on error.
 function M.flashImageVersion(versionEntry, noRetain, devType, isFactory)
-	if log then log:info("flashImageVersion") end
+	if log then log:info(MOD_ABBR, "flashImageVersion") end
 	local imgName = M.constructImageFilename(versionEntry.version, devType, isFactory)
 	local cmd = noRetain and 'sysupgrade -n ' or 'sysupgrade '
 	cmd = cmd .. cachePath .. '/' .. imgName

src/script/d3dapi

@@ -10,15 +10,16 @@
 
 LUA=lua
 SCRIPT_PATH=/usr/share/lua/wifibox
-LOG_FILE=/tmp/wifibox.log
+LOG_FILE=/tmp/wifibox.stdout.log
 
 cd $SCRIPT_PATH
-echo "CGI invocation" >> $LOG_FILE
+#echo "CGI invocation" >> $LOG_FILE
 #strace -o /tmp/trace-$$.log -ff $LUA ./cmdmain.lua $@ 2>> $LOG_FILE
 $LUA ./cmdmain.lua $@ 2>> $LOG_FILE
 
 exit $?
 
+
 # Code below is for debugging incoming CGI data
 read -n $CONTENT_LENGTH POSTDATA
 echo -e "Content-type: text/plain\r\n\r\n"

src/script/loglite-filters.lua

@@ -0,0 +1,63 @@
+local M = {}
+
+M.default = {
+	['options'] = { mode = 'keep', count = 'none' },
+	['patterns'] = {
+		['%(error%)'] = 'red',
+		['%(warning%)'] = 'yellow',
+		['%(bulk%)'] = 'gray',
+		['setState%(%)'] = 'bblue'
+	}
+}
+
+-- filter rules for firmware log (/tmp/wifibox.log)
+M.firmware = {
+	['parent'] = 'default',
+	['patterns'] = {
+		['START%-RQ'] = 'bblue',
+		['END%-RQ'] = 'blue'
+	}
+}
+
+-- filter rules for print3d log (/tmp/print3d-*.log)
+M.print3d = {
+	['parent'] = 'default',
+	['patterns'] = {
+		['Print 3D server'] = 'byellow',
+		['sendCode%(%)'] = 'green',
+		['readCode%(%)'] = 'blue',
+		['readResponseCode%(%)'] = 'blue'
+	}
+}
+
+-- filter rules for serial communcation of print3d
+M.serial = {
+	['options'] = { mode = 'delete', count = 'none' },
+	['patterns'] = {
+		['Print 3D server'] = 'byellow,_nodelete',
+		['sendCode%(%)'] = 'green,_nodelete',
+		['readCode%(%)'] = 'blue,_nodelete',
+		['readResponseCode%(%)'] = 'blue,_nodelete',
+		['setState%(%)'] = 'bblue,_nodelete',
+		['%[ABSD%]'] = 'gray,_nodelete', -- 0.10.10
+		['%[ABD%]'] = 'gray,_nodelete', -- 0.10.9
+		['%(info%)'] = 'gray,_nodelete' -- 0.10.10
+	}
+}
+
+
+M.test = {  -- TEST set
+	['options'] = { mode = 'keep', count = 'all' },
+	['patterns'] = {
+		['%(info%)'] = 'yellow'
+	}
+}
+
+M.printstart = {
+	['options'] = { mode = 'delete' },
+	['patterns'] = {
+		['print started'] = '_uppercase,bwhite'
+	}
+}
+
+return M

src/script/loglite.lua

@@ -0,0 +1,275 @@
+#!/usr/bin/env lua
+
+--[[
+For documentation on this script, see README-loglite.md.
+
+Ideas for improvement:
+* add more directives like uppercase, prefix/suffix?
+* create separate package for this script: a) since it is useful for any log file, b) this file is getting somewhat long
+* for broader terminal support: detect `tput` and use it if available (http://wiki.bash-hackers.org/scripting/terminalcodes)
+* pre-split keyword lists for efficiency instead of redoing this at every new line?
+
+FIXME:
+* with deleteMode enabled, multiple matches and _nodelete in a later match, previous directives are ignored
+]]--
+
+
+--[[========================================================================]]--
+
+--Note: overview of ANSI escape codes: http://ascii-table.com/ansi-escape-sequences.php (support varies per terminal/termtype)
+local ANSI_COLORS = {
+	['bold'] = 1,
+	['underscore'] = 4,
+	['blink'] = 5, -- on osx/iterm2, this has to be enabled in preferences
+	['reverse'] = 7,
+	['black'] = 30,
+	['red'] = 31,
+	['green'] = 32,
+	['yellow'] = 33,
+	['blue'] = 34,
+	['magenta'] = 35,
+	['cyan'] = 36,
+	['white'] = 37,
+	['bblack'] = 40,
+	['bred'] = 41,
+	['bgreen'] = 42,
+	['byellow'] = 43,
+	['bblue'] = 44,
+	['bmagenta'] = 45,
+	['bcyan'] = 46,
+	['bwhite'] = 47
+}
+
+local ESCAPE_STR = string.char(27) .. "["
+local RESET_CODE = ESCAPE_STR .. "m"
+
+local DFL_FILTERSET_FILE = "loglite-filters.lua"
+
+
+
+--[[========================================================================]]--
+
+--- Stringifies the given object.
+-- From util/utils.lua
+-- Note that self-referencing objects will cause an endless loop with the current implementation.
+-- @param o The object to convert.
+-- @treturn string Stringified version of o.
+local function dump(o)
+	if type(o) == 'table' then
+		local s = '{ '
+		for k,v in pairs(o) do
+			if type(k) ~= 'number' then k = '"'..k..'"' end
+			s = s .. '['..k..'] = ' .. dump(v) .. ','
+		end
+		return s .. '} '
+	else
+		return tostring(o)
+	end
+end
+
+--- Splits a string on a given divider character.
+-- From util/utils.lua
+-- @string[opt=':'] div The divider character to use.
+-- @return An array containing the resultant substrings.
+-- @usage local str = "a,b,c"; local parts = str:split(',')
+function string:split(div)
+	local div, pos, arr = div or ':', 0, {}
+	for st,sp in function() return self:find(div, pos, true) end do
+		table.insert(arr, self:sub(pos, st - 1))
+		pos = sp + 1
+	end
+	table.insert(arr, self:sub(pos))
+	return arr
+end
+
+--- Determines if filename exists and can be opened for reading.
+-- From http://stackoverflow.com/a/4991602
+-- @string filename The file to test.
+-- @return True if the file exists and is readable, false otherwise.
+function fileExists(filename)
+   local f = io.open(filename, "r")
+   if f ~= nil then io.close(f) return true else return false end
+end
+
+--- Converts keys of a table into a string.
+-- Adapted from http://stackoverflow.com/a/12674376.
+-- @string tbl A key/value table.
+-- @string[opt=','] sep Separator to use between items.
+-- @boolean[opt=false] sort Whether or not to sort the resulting list.
+-- @return A string with all keys from the given table.
+local function keysToString(tbl, sep, sort)
+	local sep, sort = sep or ',', sort or false
+	local keyset, n = {}, 0
+	for k,_ in pairs(tbl) do
+		n = n + 1
+		keyset[n] = k
+	end
+	if sort then table.sort(keyset) end
+	return table.concat(keyset, sep)
+end
+
+--- Merge two tables recursively (i.e., subtables also get merged).
+-- from: http://stackoverflow.com/a/1283608
+-- @table t1 Table to merge into.
+-- @table t2 Table to merge into t1.
+-- @return The combined table (actually t1).
+function mergeTables(t1, t2)
+	for k,v in pairs(t2) do
+		if type(v) == "table" then
+			if type(t1[k] or false) == "table" then
+				mergeTables(t1[k] or {}, t2[k] or {})
+			else
+				t1[k] = v
+			end
+		else
+			t1[k] = v
+		end
+	end
+	return t1
+end
+
+local function hasValue(t, needle)
+	for k,v in pairs(t) do
+		if needle == v then return k end
+	end
+	return nil
+end
+
+local function makeAnsiCode(key)
+	if not ANSI_COLORS[key] then return nil end
+	return ESCAPE_STR .. ANSI_COLORS[key] .. 'm'
+end
+
+
+
+--[[========================================================================]]--
+
+local function tailStream(stream, filterSet)
+	patterns = filterSet and filterSet.patterns or {}
+	options = filterSet and filterSet.options or { ['mode'] = 'keep' }
+	local c = 0
+
+	for line in stream:lines() do
+		--c = c + 1 -- Note: this would also count deleted lines
+		local embellished = line
+		local keepLine = (options.mode == 'keep')
+		local keepLineOverridden = false
+
+		-- look for a pattern matching this line
+		for p,c in pairs(patterns) do
+			if line:match(p) then
+				-- print("[DEBUG] +matched rule '" .. p .. "'/'" .. c .. "' against '" .. line .. "'")
+				local kws = c:split(',')
+
+				if hasValue(kws, '_delete') then keepLine = false; keepLineOverridden = true
+				elseif hasValue(kws, '_nodelete') then keepLine = true; keepLineOverridden = true
+				end
+
+				if keepLine then
+					-- first collect formatting sequences
+					local fmt = ''
+					for _,kw in ipairs(kws) do
+						local code = makeAnsiCode(kw)
+						if code then fmt = fmt .. code end
+					end
+
+					-- then wrap the line in formatting, if any
+					if fmt:len() > 0 then embellished = fmt .. embellished .. RESET_CODE end
+				else
+					-- Note: break out of loop and stop processing when line should be deleted _if_ the default has been overridden to do so
+					if keepLineOverridden then
+						embellished = nil
+						break
+					end
+				end
+
+				--break -- Note: don't break, allow multiple matches per line, e.g. to mix and match fg and bg colors
+			end
+		end
+
+		if embellished and keepLine then
+			c = c + 1
+
+			if options.count == 'all' then print(c, embellished)
+			else print(embellished) end
+		else
+			-- print("[DEBUG] -skipped '"..line.."'")
+		end
+
+		--c = line:match 'truncated' and 0 or c -- from tail on stderr apparently
+	end
+end
+
+--TODO: could be extended to look for multiple filenames in multiple paths
+local function readConfigFile(filename, searchPath)
+	fullPath = searchPath .. '/' .. filename
+	if not fileExists(fullPath) then
+		--print("[DEBUG] config file '" .. fullPath .. "' not found")
+		return nil
+	end
+
+	--print("[DEBUG] using config file '" .. fullPath .. "'")
+	-- require does not accept full paths? also, pcall does not help with dofile
+	return dofile(fullPath)
+end
+
+--- Load filter set with given name from configSets, with inheritance as specified.
+local function readFilterSet(configSets, setName)
+	local result = {}
+	for k,_ in pairs(configSets) do
+		if k == setName then
+			parent = configSets[setName]['parent']
+			if parent ~= nil then
+				--print("[DEBUG] recursing for filter set '" .. parent .. "' from config")
+				result = mergeTables(result, readFilterSet(configSets, parent))
+			end
+			--print("[DEBUG] using/merging filter set '" .. setName .. "' from config")
+			result = mergeTables(result, configSets[setName])
+			break
+		end
+	end
+	return result
+end
+
+--NOTE: if command-line options get any more complex, switch to a lightweight
+--      getopt like this one? https://attractivechaos.wordpress.com/2011/04/07/getopt-for-lua/
+local function main()
+	-- handle command-line arguments
+	local showHelp, followFile, filterSetName = false, nil, 'default'
+	if #arg > 0 and arg[1] == "-h" or arg[1] == "--help" then
+		showHelp = true
+	else
+		if #arg > 0 and arg[1] ~= '-' then followFile = arg[1] end
+		if #arg > 1 then filterSetName = arg[2] end
+	end
+
+	-- read filter set file if available
+	local configSets = readConfigFile(DFL_FILTERSET_FILE, os.getenv('HOME')) or {}
+	local filterSet = readFilterSet(configSets, filterSetName)
+	-- print("[DEBUG] final filter set for '" .. filterSetName .. "' from config: " .. dump(filterSet))
+
+	-- if requested, display help and exit
+	if showHelp and showHelp == true then
+		print("Usage: loglite.lua [file-to-tail] [filter-set]")
+		print("  If no arguments are supplied, or if the first one is `-', stdin is used as input.")
+		print("  If no filter set is supplied, a set named `default' will be looked for.")
+		print("  Filter sets can be defined in a file `loglite-filters.lua' in your home directory.")
+		print()
+		print("  Available filter sets in " .. os.getenv('HOME') .. "/" .. DFL_FILTERSET_FILE .. ": " .. keysToString(configSets, ', ', true))
+		os.exit(0)
+	end
+
+
+	-------------------------
+
+	--print("[DEBUG] following file: '" .. (followFile and followFile or "<stdin>") .. "', with filter set '" .. filterSetName .. "'.")
+
+	--Info on tailing a file: https://stackoverflow.com/questions/17363973/how-can-i-tail-f-a-log-filetruncate-aware-in-lua
+	--local tailin = io.popen('tail -F '..(...)..' 2>&1', 'r')
+	local tailin = followFile and io.popen('tail -f ' .. followFile, 'r') or io.stdin
+
+	pcall(tailStream, tailin, filterSet) -- Note: protected call to suppress interrupt error thrown by lines iterator
+end
+
+main()
+os.exit(0)

src/script/logrotate-wifibox.conf

@@ -0,0 +1,36 @@
+# Doodle3D logrotate configuration
+
+compress
+su
+create
+
+/tmp/wifibox.log /tmp/print3d-*.log {
+	rotate 2
+	size 1000k
+	missingok
+	olddir /tmp/wifibox-rotated
+
+	# as alternative to copytruncate (which *might* miss lines) we could implement
+	# SIGUSR1 in print3d and firmware to reopen their logs
+	copytruncate  # 'create' is ignored with copytruncate, as the file stays in place
+
+	prerotate
+		FIRST_N_LINES=500
+		PRINT3D_LOGHEAD_FILE=print3d-loghead
+		WIFIBOX_LOGHEAD_FILE=wifibox-loghead
+		ROTATED_FILES_PATH=/tmp/wifibox-rotated
+
+		#Note: by looking at creation date of the print3d socket and comparing against that
+		#      of print3d-loghead we could detect a server restart (e.g. due to reconnected printer)
+
+		echo "$1" | grep -q "print3d-.*\.log"
+		if [ $? -eq 0 -a ! -f "$ROTATED_FILES_PATH/$PRINT3D_LOGHEAD_FILE" ]; then
+			head -q -n$FIRST_N_LINES "$1" > "$ROTATED_FILES_PATH/$PRINT3D_LOGHEAD_FILE"
+		fi
+
+		echo "$1" | grep -q "wifibox.log"
+		if [ $? -eq 0 -a ! -f "$ROTATED_FILES_PATH/$WIFIBOX_LOGHEAD_FILE" ]; then
+			head -q -n$FIRST_N_LINES "$1" > "$ROTATED_FILES_PATH/$WIFIBOX_LOGHEAD_FILE"
+		fi
+	endscript
+}

src/script/wifibox.uci.config

@@ -1,5 +1,12 @@
 config settings 'system'
-	option logfile '/tmp/wifibox.log'
+		#In addition to regular text, api_log_filename and p3d_log_basename may also be
+		#a stream enclose in angle brackets (e.g. '<stderr>') or
+		#a command to send output to in back quotes (e.g. '`ssh USER@HOST "cat > /tmp/test.log"`').
+		#Note that using an SSH tunnel without public key auth will need interaction
+
+        option log_path '/tmp'
+        option api_log_filename 'wifibox.log'
+        option p3d_log_basename 'print3d'
 
 config settings 'general'
 	option printer_type 'ultimaker'

src/script/wifibox_init

@@ -20,6 +20,8 @@ boot() {
 	$LOGGER "Start signing in..."
 	/usr/share/lua/wifibox/script/signin.sh > /dev/null 2> /dev/null &
 	
+	mkdir -p /var/lib  # required by logrotate for logrotate.status
+	mkdir -p /tmp/wifibox-rotated  # this is where rotated wifibox logs are placed
 }
 
 start() {

src/util/access.lua

@@ -10,6 +10,8 @@ local log = require('util.logger')
 local utils = require('util.utils')
 local printerUtils = require('util.printer')
 
+local MOD_ABBR = "UACS"
+
 local M = {}
 
 function M.hasControl(ip)
@@ -41,7 +43,7 @@ end
 function M.getController()
 	local file, error = io.open('/tmp/controller.txt','r')
 	if file == nil then
-		--log:error("Util:Access:Can't read controller file. Error: "..error)
+		--log:error(MOD_ABBR, "Util:Access: Can't read controller file. Error: "..error)
 		return ""
 	else
 		controllerIP = file:read('*a')

src/util/logger.lua

@@ -13,36 +13,51 @@ local utils = require('util.utils')
 
 local M = {}
 
-local logLevel, logVerbose, logStream
+local logLevel, logVerboseFmt, logStream
+local logFilePath = nil -- only used for reference
 
---- Available log levels
+local LONGEST_LEVEL_NAME = -1
+
+--- Available log levels (starting at 1)
 -- @table LEVEL
 M.LEVEL = {
-	'debug', -- for debug messages
+	'quiet',		-- not used for logging, only for setting levels
-	'info', -- for informational messages
+	'error',		-- fatal or non-fatal error condition
-	'warn', -- for warnings (something is wrong/fishy but not neccesarily problematic)
+	'warning',	-- possibly troublesome situation
-	'error', -- for recoverable errors
+	'info',			-- information about what the application is doing
-	'fatal' -- for unrecoverable errors
+	'verbose',	-- extra trail information on what the application is doing
+	'bulk'			-- debug information (in large amounts)
 }
 
--- M.LEVEL already has idx=>name entries, now create name=>idx entries
+
+--[[== module initialization code ==]]--
+
+-- M.LEVEL already has idx=>name entries, now create name=>idx entries so it can be indexed both ways, and init LONGEST_LEVEL_NAME
 for i,v in ipairs(M.LEVEL) do
 	M.LEVEL[v] = i
+	if v:len() > LONGEST_LEVEL_NAME then LONGEST_LEVEL_NAME = v:len() end
 end
 
 
-local function log(level, msg, verbose)
+--[[================================]]--
-	if level >= logLevel then
+
-		local now = os.date('%m-%d %H:%M:%S')
+
+local function log(level, module, msg, verboseFmt)
+	if level <= logLevel then
+		local now = os.date('%d-%m %H:%M:%S')
 		local i = debug.getinfo(3) --the stack frame just above the logger call
-		local v = verbose
+		local v = verboseFmt
-		if v == nil then v = logVerbose end
+		if v == nil then v = logVerboseFmt end
 		local name = i.name or "(nil)"
 		local vVal = 'nil'
 		local m = (type(msg) == 'string') and msg or utils.dump(msg)
+		if module == nil then module = "LUA " end
 
-		if v then logStream:write(now .. " (" .. M.LEVEL[level] .. ")     " .. m .. "  [" .. name .. "@" .. i.short_src .. ":" .. i.linedefined .. "]\n")
+		local levelName = M.LEVEL[level]
-		else logStream:write(now .. " (" .. M.LEVEL[level] .. ")     " .. m .. "\n") end
+		local padding = string.rep(' ', LONGEST_LEVEL_NAME - levelName:len())
+
+		if v then logStream:write(now .. " [" .. module .. "] (" .. levelName .. ")" .. padding .. ": " .. m .. "  [" .. name .. "@" .. i.short_src .. ":" .. i.linedefined .. "]\n")
+		else logStream:write(now .. " [" .. module .. "] (" .. levelName .. ")" .. padding .. ": " .. m .. "\n") end
 
 		logStream:flush()
 	end
@@ -51,11 +66,16 @@ end
 
 --- Initializes the logger.
 -- @tparam @{util.logger.LEVEL} level Minimum level of messages to log.
--- @tparam bool verbose Write verbose log messages (include file/line inforomation).
+-- @tparam bool verbose Write verbose log messages (include file/line information).
-function M:init(level, verbose)
+function M:init(level, verboseFmt)
-	logLevel = level or M.LEVEL.warn
+	logLevel = level or M.LEVEL.warning
-	logVerbose = verbose or false
+	logVerboseFmt = verboseFmt or false
-	logStream = stream or io.stdout
+	--logStream = stream or io.stdout
+end
+
+function M:setLevel(level, verboseFmt)
+	logLevel = level or M.LEVEL.warning
+	logVerboseFmt = verboseFmt or false
 end
 
 -- pass nil as stream to reset to stdout
@@ -63,10 +83,21 @@ function M:setStream(stream)
 	logStream = stream or io.stdout
 end
 
-function M:debug(msg, verbose) log(M.LEVEL.debug, msg, verbose); return true end
+function M:getLevel()
-function M:info(msg, verbose) log(M.LEVEL.info, msg, verbose); return true end
+	return logLevel, logVerboseFmt
-function M:warn(msg, verbose) log(M.LEVEL.warn, msg, verbose); return true end
+end
-function M:error(msg, verbose) log(M.LEVEL.error, msg, verbose); return false end
+
-function M:fatal(msg, verbose) log(M.LEVEL.fatal, msg, verbose); return false end
+function M:getStream()
+	return logStream
+end
+
+function M:setLogFilePath(path) logFilePath = path end
+function M:getLogFilePath() return logFilePath end
+
+function M:error(module, msg, verboseFmt) log(M.LEVEL.error, module, msg, verboseFmt); return false end
+function M:warning(module, msg, verboseFmt) log(M.LEVEL.warning, module, msg, verboseFmt); return true end
+function M:info(module, msg, verboseFmt) log(M.LEVEL.info, module, msg, verboseFmt); return true end
+function M:verbose(module, msg, verboseFmt) log(M.LEVEL.verbose, module, msg, verboseFmt); return true end
+function M:bulk(module, msg, verboseFmt) log(M.LEVEL.bulk, module, msg, verboseFmt); return true end
 
 return M

src/util/printer.lua

@@ -10,6 +10,8 @@ local log = require('util.logger')
 local utils = require('util.utils')
 local printDriver = require('print3d')
 
+local MOD_ABBR = "UPRN"
+
 local SUPPORTED_PRINTERS = {
 	rigidbot = "Rigidbot",
 	ultimaker = "Ultimaker",
@@ -59,7 +61,8 @@ local SUPPORTED_PRINTERS = {
 	colido_m2020 = "ColiDo M2020",
 	colido_x3045 = "ColiDo X3045",
 	colido_compact = "ColiDo Compact",
-	colido_diy = "ColiDo DIY"
+	colido_diy = "ColiDo DIY",
+	craftbot_plus = "CraftBot PLUS"
 }
 local SUPPORTED_BAUDRATES = {
 	["115200"] = "115200 bps",
@@ -81,8 +84,8 @@ end
 --returns a printer instance or nil (and sets error state on response in the latter case)
 function M.createPrinterOrFail(deviceId, response)
 
-	--log:debug("API:printer:createPrinterOrFail: "..utils.dump(deviceId))
+	--log:info(MOD_ABBR, "API:printer:createPrinterOrFail: "..utils.dump(deviceId))
-	local msg,printer = nil, nil
+	local rv,msg,printer = nil, nil, nil
 
 	if deviceId == nil or deviceId == "" then
 		printer,msg = printDriver.getPrinter()
@@ -98,6 +101,18 @@ function M.createPrinterOrFail(deviceId, response)
 		return nil
 	end
 
+	-- only log these log setup errors, do not let them prevent further request handling
+
+	rv,msg = printer:setLocalLogStream(log:getStream())
+	if not rv then
+		log:error(MOD_ABBR, "could not set log stream in Lua binding (" .. msg .. ")")
+	end
+
+	rv,msg = printer:setLocalLogLevel(log:getLevel())
+	if not rv then
+		log:error(MOD_ABBR, "could not set log level '" .. log:getLevel() .. "' in Lua binding (" .. msg .. ")")
+	end
+
 	return printer
 end
 

src/util/settings.lua

@@ -19,6 +19,8 @@ local baseconfig = require('conf_defaults')
 local utils = require('util.utils')
 local log = require('util.logger')
 
+local MOD_ABBR = "USET"
+
 local M = {}
 
 --- UCI config name (i.e., file under `/etc/config`)
@@ -159,7 +161,7 @@ end]]--
 -- @return The associated value, beware (!) that this may be boolean false for keys of 'bool' type, or nil if the key could not be read because of a UCI error.
 -- @treturn string Message in case of error.
 function M.get(key)
-	--log:info("settings:get: "..utils.dump(key))
+	--log:info(MOD_ABBR, "settings:get: "..utils.dump(key))
 	key = replaceDots(key)
 	
 	-- retrieve settings's base settings from conf_defaults.lua
@@ -177,7 +179,7 @@ function M.get(key)
 	local uciV,msg = uci:get(UCI_CONFIG_NAME, section, key)
 	if not uciV and msg ~= nil then
 		local errorMSG = "Issue reading setting '"..utils.dump(key).."': "..utils.dump(msg);
-		log:info(errorMSG)
+		log:warning(MOD_ABBR, errorMSG)
 		return nil, errorMSG;
 	end
 	
@@ -244,21 +246,21 @@ end
 -- @treturn bool|nil True if everything went well, false if validation error, nil in case of error.
 -- @treturn ?string Error message in case first return value is nil (invalid key).
 function M.set(key, value, noCommit)
-	log:info("settings:set: "..utils.dump(key).." to: "..utils.dump(value))
+	--log:info(MOD_ABBR, "settings:set: "..utils.dump(key).." to: "..utils.dump(value))
 	key = replaceDots(key)
 
 	local r = utils.create(UCI_CONFIG_FILE)
 	local rv, msg = uci:set(UCI_CONFIG_NAME, UCI_CONFIG_SECTION, UCI_CONFIG_TYPE)
 	if not rv and msg ~= nil then
 		local errorMSG = "Issue creating section '"..utils.dump(UCI_CONFIG_SECTION).."': "..utils.dump(msg);
-		log:info(errorMSG)
+		log:warning(MOD_ABBR, errorMSG)
 		return nil, errorMSG;
 	end
 
 	local base = getBaseKeyTable(key)
 	if not base then return false,ERR_NO_SUCH_KEY end
 
-	--log:info("  base.type: "..utils.dump(base.type))
+	--log:info(MOD_ABBR, "  base.type: "..utils.dump(base.type))
 	if base.type == 'bool' then
 		if value ~= "" then
 			value = utils.toboolean(value)
@@ -283,7 +285,7 @@ function M.set(key, value, noCommit)
 		local rv, msg = uci:set(UCI_CONFIG_NAME, section, UCI_CONFIG_TYPE)
 		if not rv and msg ~= nil then
 			local errorMSG = "Issue getting subsection '"..utils.dump(base.subSection).."': "..utils.dump(msg);
-			log:info(errorMSG)
+			log:warning(MOD_ABBR, errorMSG)
 			return nil, errorMSG;
 		end
 	end
@@ -292,14 +294,14 @@ function M.set(key, value, noCommit)
 		local rv, msg = uci:set(UCI_CONFIG_NAME, section, key, toUciValue(value, base.type))
 		if not rv and msg ~= nil then
 			local errorMSG = "Issue setting setting '"..utils.dump(key).."' in section '"..utils.dump(section).."': "..utils.dump(msg);
-			log:info(errorMSG)
+			log:warning(MOD_ABBR, errorMSG)
 			return nil, errorMSG;
 		end
 	else
 		local rv, msg = uci:delete(UCI_CONFIG_NAME, section, key)
 		if not rv and msg ~= nil then
 			local errorMSG = "Issue deleting setting '"..utils.dump(key).."' in section '"..utils.dump(section).."': "..utils.dump(msg);
-			log:info(errorMSG)
+			log:warning(MOD_ABBR, errorMSG)
 			return nil, errorMSG;
 		end
 	end
@@ -318,13 +320,13 @@ end
 -- @string key The key to set.
 -- @treturn bool|nil True if everything went well, nil in case of error.
 function M.resetAll()
-	log:info("settings:resetAll")
+	log:info(MOD_ABBR, "settings:resetAll")
 
 	-- find all sections
 	local allSections, msg = uci:get_all(UCI_CONFIG_NAME)
 	if not allSections and msg ~= nil then
 		local errorMSG = "Issue reading all settings: "..utils.dump(msg);
-		log:info(errorMSG)
+		log:warning(MOD_ABBR, errorMSG)
 		return nil, errorMSG;
 	end
 
@@ -334,7 +336,7 @@ function M.resetAll()
 			local rv, msg = uci:delete(UCI_CONFIG_NAME,key)
 			if not rv and msg ~= nil then
 				local errorMSG = "Issue deleting setting '"..utils.dump(key).."': "..utils.dump(msg);
-				log:info(errorMSG)
+				log:warning(MOD_ABBR, errorMSG)
 				return nil, errorMSG;
 			end
 		end
@@ -356,7 +358,7 @@ end
 -- @p[opt=nil] noCommit If true, do not commit the uci configuration; this is more efficient when resetting multiple values
 -- @treturn bool|nil True if everything went well, nil in case of error.
 function M.reset(key, noCommit)
-	log:info("settings:reset: "..utils.dump(key))
+	log:info(MOD_ABBR, "settings:reset: "..utils.dump(key))
 
 	-- delete
 	key = replaceDots(key)
@@ -371,7 +373,7 @@ function M.reset(key, noCommit)
 	--   (which always happens when reset is used in resetall) it will also generate a error
 	--if not rv and msg ~= nil then
 	--	local errorMSG = "Issue deleting setting '"..utils.dump(key).."' in section '"..section.."': "..utils.dump(msg);
-	--	log:info(errorMSG)
+	--	log:warning(MOD_ABBR, errorMSG)
 	--	return nil, errorMSG;
 	--end
 

src/util/status.lua

@@ -9,6 +9,8 @@
 local log = require('util.logger')
 local utils = require('util.utils')
 
+local MOD_ABBR = "USTS"
+
 local M = {}
 
 local FOLDER = "/tmp/"
@@ -23,7 +25,7 @@ function M.get(fileName)
 	local path = getPath(fileName)
 	local file, error = io.open(path,'r')
 	if file == nil then
-		--log:error("Util:Access:Can't read controller file. Error: "..error)
+		--log:warning(MOD_ABBR, "Util:Access:Can't read controller file. Error: "..error)
 		return "",""
 	else
 		local status = file:read('*a')
@@ -35,7 +37,7 @@ function M.get(fileName)
 end
 
 function M.set(fileName,code,msg)
-	--log:info("setStatus: "..code.." | "..msg)
+	--log:info(MOD_ABBR, "setStatus: "..code.." | "..msg)
 	local path = getPath(fileName)
 	local file = io.open(path,'w')
 	file:write(code.."|"..msg)