Picroft 18.08 release 5 replies four times

watou · November 12, 2018, 11:14am

After my Picroft (AIY Voice Kit V1, Pi3B+) upgraded itself to 18.08 release 5, it now replies to every question four times. Sometimes with the same answer, sometimes with a slightly different phrasing. It’s like he has a new mental disorder like echopalilalia, poor guy.

But seriously, how can I get my instance to only answer my question just the once?

Thanks!

KathyReid · November 12, 2018, 11:18am

Can you please provide your log files?
They are in /var/log/mycroft. Pastebin is usually the best way, or a Google Drive or Dropbox link, then we can see what’s going on.

watou · November 12, 2018, 11:24am

I have a 123MB skills.log file! Recommendation on the least tedious way to get you the parts of the log you’re after?

/var/log/mycroft $ ls -al
total 121932
drwxrwxrwx 2 root root      4096 Oct 21 12:12 .
drwxr-xr-x 5 root root      4096 Nov 12 06:25 ..
-rw-r--r-- 1 pi   pi      608211 Nov 12 11:18 audio.log
-rw-r--r-- 1 pi   pi       29115 Nov  9 10:06 bus.log
-rw-r--r-- 1 pi   pi   123634065 Nov 12 11:22 skills.log
-rw-r--r-- 1 pi   pi      550784 Nov 12 11:17 voice.log

Ah, I seem to have DEBUG level turned on, but is this not hitting the servers too much?

11:23:26.695 - urllib3.connectionpool - DEBUG - https://api.mycroft.ai:443 "GET /v1/device/7bdc1a1a-acad-4270-aa76-77ef63c01a20/setting HTTP/1.1" 304 0
11:23:26.723 - urllib3.connectionpool - DEBUG - Starting new HTTPS connection (1): api.mycroft.ai:443
11:23:26.871 - urllib3.connectionpool - DEBUG - https://api.mycroft.ai:443 "GET /v1/device/7bdc1a1a-acad-4270-aa76-77ef63c01a20/setting HTTP/1.1" 304 0
11:23:26.891 - urllib3.connectionpool - DEBUG - Starting new HTTPS connection (1): api.mycroft.ai:443
11:23:27.339 - urllib3.connectionpool - DEBUG - https://api.mycroft.ai:443 "GET /v1/device/7bdc1a1a-acad-4270-aa76-77ef63c01a20/location HTTP/1.1" 304 0
11:23:27.367 - urllib3.connectionpool - DEBUG - Starting new HTTPS connection (1): api.mycroft.ai:443
11:23:27.527 - urllib3.connectionpool - DEBUG - https://api.mycroft.ai:443 "GET /v1/device/7bdc1a1a-acad-4270-aa76-77ef63c01a20/location HTTP/1.1" 304 0
11:23:27.567 - urllib3.connectionpool - DEBUG - Starting new HTTPS connection (1): api.mycroft.ai:443
11:23:28.071 - urllib3.connectionpool - DEBUG - https://api.mycroft.ai:443 "GET /v1/device/7bdc1a1a-acad-4270-aa76-77ef63c01a20/setting HTTP/1.1" 304 0
11:23:28.089 - urllib3.connectionpool - DEBUG - Starting new HTTPS connection (1): api.mycroft.ai:443
11:23:28.214 - urllib3.connectionpool - DEBUG - https://api.mycroft.ai:443 "GET /v1/device/7bdc1a1a-acad-4270-aa76-77ef63c01a20/setting HTTP/1.1" 304 0
11:23:28.233 - urllib3.connectionpool - DEBUG - Starting new HTTPS connection (1): api.mycroft.ai:443
11:23:28.700 - urllib3.connectionpool - DEBUG - https://api.mycroft.ai:443 "GET /v1/device/7bdc1a1a-acad-4270-aa76-77ef63c01a20/location HTTP/1.1" 304 0
11:23:28.900 - urllib3.connectionpool - DEBUG - https://api.mycroft.ai:443 "GET /v1/device/7bdc1a1a-acad-4270-aa76-77ef63c01a20/location HTTP/1.1" 304 0
11:23:29.389 - urllib3.connectionpool - DEBUG - Starting new HTTPS connection (1): api.mycroft.ai:443
11:23:30.022 - urllib3.connectionpool - DEBUG - https://api.mycroft.ai:443 "GET /v1/device/7bdc1a1a-acad-4270-aa76-77ef63c01a20/skill HTTP/1.1" 304 0
11:23:30.073 - SKILLS - DEBUG - {"context": null, "data": {}, "type": "mycroft-date-time.mycroftai:TimeSkillupdate_display"}
11:23:30.239 - SKILLS - DEBUG - {"context": null, "data": {}, "type": "mycroft-date-time.mycroftai:TimeSkillupdate_display"}
11:23:32.516 - urllib3.connectionpool - DEBUG - Starting new HTTPS connection (1): api.mycroft.ai:443
11:23:33.137 - urllib3.connectionpool - DEBUG - https://api.mycroft.ai:443 "GET /v1/device/7bdc1a1a-acad-4270-aa76-77ef63c01a20/skill HTTP/1.1" 304 0
11:23:34.521 - urllib3.connectionpool - DEBUG - Starting new HTTPS connection (1): api.mycroft.ai:443
11:23:34.894 - urllib3.connectionpool - DEBUG - Starting new HTTPS connection (1): api.mycroft.ai:443
11:23:35.136 - urllib3.connectionpool - DEBUG - https://api.mycroft.ai:443 "GET /v1/device/7bdc1a1a-acad-4270-aa76-77ef63c01a20/skill HTTP/1.1" 304 0
11:23:35.529 - urllib3.connectionpool - DEBUG - https://api.mycroft.ai:443 "GET /v1/device/7bdc1a1a-acad-4270-aa76-77ef63c01a20/skill HTTP/1.1" 304 0
11:23:37.233 - urllib3.connectionpool - DEBUG - Starting new HTTPS connection (1): api.mycroft.ai:443
11:23:37.875 - urllib3.connectionpool - DEBUG - https://api.mycroft.ai:443 "GET /v1/device/7bdc1a1a-acad-4270-aa76-77ef63c01a20/skill HTTP/1.1" 304 0
11:23:40.091 - SKILLS - DEBUG - {"context": null, "data": {}, "type": "mycroft-date-time.mycroftai:TimeSkillupdate_display"}
11:23:40.255 - SKILLS - DEBUG - {"context": null, "data": {}, "type": "mycroft-date-time.mycroftai:TimeSkillupdate_display"}
11:23:48.100 - SKILLS - DEBUG - {"context": null, "data": {}, "type": "mycroft-reminder.mycroftai:reminder"}
11:23:48.262 - SKILLS - DEBUG - {"context": null, "data": {}, "type": "mycroft-reminder.mycroftai:reminder"}
11:23:50.105 - SKILLS - DEBUG - {"context": null, "data": {}, "type": "mycroft-date-time.mycroftai:TimeSkillupdate_display"}
11:23:50.267 - SKILLS - DEBUG - {"context": null, "data": {}, "type": "mycroft-date-time.mycroftai:TimeSkillupdate_display"}
11:24:00.120 - SKILLS - DEBUG - {"context": null, "data": {}, "type": "mycroft-date-time.mycroftai:TimeSkillupdate_display"}
11:24:00.282 - SKILLS - DEBUG - {"context": null, "data": {}, "type": "mycroft-date-time.mycroftai:TimeSkillupdate_display"}
11:24:10.141 - SKILLS - DEBUG - {"context": null, "data": {}, "type": "mycroft-date-time.mycroftai:TimeSkillupdate_display"}
11:24:10.294 - SKILLS - DEBUG - {"context": null, "data": {}, "type": "mycroft-date-time.mycroftai:TimeSkillupdate_display"}
11:24:18.151 - SKILLS - DEBUG - {"context": null, "data": {}, "type": "mycroft-reminder.mycroftai:reminder"}
11:24:18.307 - SKILLS - DEBUG - {"context": null, "data": {}, "type": "mycroft-reminder.mycroftai:reminder"}
11:24:20.150 - SKILLS - DEBUG - {"context": null, "data": {}, "type": "mycroft-date-time.mycroftai:TimeSkillupdate_display"}
11:24:20.311 - SKILLS - DEBUG - {"context": null, "data": {}, "type": "mycroft-date-time.mycroftai:TimeSkillupdate_display"}
11:24:25.272 - urllib3.connectionpool - DEBUG - Starting new HTTPS connection (1): api.mycroft.ai:443
11:24:25.996 - urllib3.connectionpool - DEBUG - https://api.mycroft.ai:443 "GET /v1/device/7bdc1a1a-acad-4270-aa76-77ef63c01a20/skill HTTP/1.1" 304 0
11:24:26.159 - SKILLS - DEBUG - {"context": null, "data": "UpdateRemote", "type": "mycroft-configuration.mycroftai:ConfigurationSkillupdate_remote"}
11:24:26.167 - urllib3.connectionpool - DEBUG - Starting new HTTPS connection (1): api.mycroft.ai:443
11:24:26.318 - SKILLS - DEBUG - {"context": null, "data": "UpdateRemote", "type": "mycroft-configuration.mycroftai:ConfigurationSkillupdate_remote"}
11:24:26.326 - urllib3.connectionpool - DEBUG - Starting new HTTPS connection (1): api.mycroft.ai:443
11:24:26.783 - urllib3.connectionpool - DEBUG - https://api.mycroft.ai:443 "GET /v1/device/7bdc1a1a-acad-4270-aa76-77ef63c01a20/setting HTTP/1.1" 304 0
11:24:26.814 - urllib3.connectionpool - DEBUG - Starting new HTTPS connection (1): api.mycroft.ai:443
11:24:26.946 - urllib3.connectionpool - DEBUG - https://api.mycroft.ai:443 "GET /v1/device/7bdc1a1a-acad-4270-aa76-77ef63c01a20/setting HTTP/1.1" 304 0
11:24:26.967 - urllib3.connectionpool - DEBUG - Starting new HTTPS connection (1): api.mycroft.ai:443
11:24:27.439 - urllib3.connectionpool - DEBUG - https://api.mycroft.ai:443 "GET /v1/device/7bdc1a1a-acad-4270-aa76-77ef63c01a20/location HTTP/1.1" 304 0
11:24:27.458 - urllib3.connectionpool - DEBUG - Starting new HTTPS connection (1): api.mycroft.ai:443
11:24:27.568 - urllib3.connectionpool - DEBUG - https://api.mycroft.ai:443 "GET /v1/device/7bdc1a1a-acad-4270-aa76-77ef63c01a20/location HTTP/1.1" 304 0
11:24:27.607 - urllib3.connectionpool - DEBUG - Starting new HTTPS connection (1): api.mycroft.ai:443
11:24:28.078 - urllib3.connectionpool - DEBUG - https://api.mycroft.ai:443 "GET /v1/device/7bdc1a1a-acad-4270-aa76-77ef63c01a20/setting HTTP/1.1" 304 0
11:24:28.096 - urllib3.connectionpool - DEBUG - Starting new HTTPS connection (1): api.mycroft.ai:443
11:24:28.225 - urllib3.connectionpool - DEBUG - https://api.mycroft.ai:443 "GET /v1/device/7bdc1a1a-acad-4270-aa76-77ef63c01a20/setting HTTP/1.1" 304 0
11:24:28.247 - urllib3.connectionpool - DEBUG - Starting new HTTPS connection (1): api.mycroft.ai:443
11:24:28.722 - urllib3.connectionpool - DEBUG - https://api.mycroft.ai:443 "GET /v1/device/7bdc1a1a-acad-4270-aa76-77ef63c01a20/location HTTP/1.1" 304 0
11:24:28.896 - urllib3.connectionpool - DEBUG - https://api.mycroft.ai:443 "GET /v1/device/7bdc1a1a-acad-4270-aa76-77ef63c01a20/location HTTP/1.1" 304 0
11:24:30.057 - urllib3.connectionpool - DEBUG - Starting new HTTPS connection (1): api.mycroft.ai:443
11:24:30.168 - SKILLS - DEBUG - {"context": null, "data": {}, "type": "mycroft-date-time.mycroftai:TimeSkillupdate_display"}
11:24:30.326 - SKILLS - DEBUG - {"context": null, "data": {}, "type": "mycroft-date-time.mycroftai:TimeSkillupdate_display"}
11:24:30.703 - urllib3.connectionpool - DEBUG - https://api.mycroft.ai:443 "GET /v1/device/7bdc1a1a-acad-4270-aa76-77ef63c01a20/skill HTTP/1.1" 304 0
11:24:33.158 - urllib3.connectionpool - DEBUG - Starting new HTTPS connection (1): api.mycroft.ai:443
11:24:33.777 - urllib3.connectionpool - DEBUG - https://api.mycroft.ai:443 "GET /v1/device/7bdc1a1a-acad-4270-aa76-77ef63c01a20/skill HTTP/1.1" 304 0
11:24:35.156 - urllib3.connectionpool - DEBUG - Starting new HTTPS connection (1): api.mycroft.ai:443
11:24:35.567 - urllib3.connectionpool - DEBUG - Starting new HTTPS connection (1): api.mycroft.ai:443
11:24:35.811 - urllib3.connectionpool - DEBUG - https://api.mycroft.ai:443 "GET /v1/device/7bdc1a1a-acad-4270-aa76-77ef63c01a20/skill HTTP/1.1" 304 0
11:24:36.216 - urllib3.connectionpool - DEBUG - https://api.mycroft.ai:443 "GET /v1/device/7bdc1a1a-acad-4270-aa76-77ef63c01a20/skill HTTP/1.1" 304 0
11:24:37.897 - urllib3.connectionpool - DEBUG - Starting new HTTPS connection (1): api.mycroft.ai:443
11:24:38.557 - urllib3.connectionpool - DEBUG - https://api.mycroft.ai:443 "GET /v1/device/7bdc1a1a-acad-4270-aa76-77ef63c01a20/skill HTTP/1.1" 304 0
11:24:40.181 - SKILLS - DEBUG - {"context": null, "data": {}, "type": "mycroft-date-time.mycroftai:TimeSkillupdate_display"}
11:24:40.342 - SKILLS - DEBUG - {"context": null, "data": {}, "type": "mycroft-date-time.mycroftai:TimeSkillupdate_display"}
11:24:48.205 - SKILLS - DEBUG - {"context": null, "data": {}, "type": "mycroft-reminder.mycroftai:reminder"}
11:24:48.354 - SKILLS - DEBUG - {"context": null, "data": {}, "type": "mycroft-reminder.mycroftai:reminder"}

KathyReid · November 12, 2018, 11:30am

OK, move each of those files to a *.BAK file, ie

mv skills.log skills.BAK

then, reboot, and Mycroft will re-create the log files.
If the issue is still occurring we’ll be able to catch it more easily.

watou · November 12, 2018, 11:42am

Thank you, @KathyReid. Here are the fresh logs. After a reboot it of course cleared up and now I’m only getting one reply instead of four, but the logs might show you something unexpected about my setup.

Also, how can I make skills.log a much smaller file (it will eventually wreck my microSD card), either by turning off DEBUG level logging, or if it’s hitting the servers too much?

Many thanks!

j1nx · November 12, 2018, 12:13pm

You can add the following line to ~/mycroft/mycroft.conf or /etc/mycroft/mycroft.conf

“log_level”: “INFO”

Example here;

github.com

j1nx/MycroftOS/blob/master/buildroot-external/rootfs-overlay/etc/mycroft/mycroft.conf#L6


{
"play_wav_cmdline": "aplay -Dhw:0,0 %1",
"play_mp3_cmdline": "mpg123 -a hw:0,0 %1",
"ipc_path": "/ramdisk/mycroft/ipc/",
"ignore_logs": ["enclosure.mouth.viseme", "enclosure.mouth.display"],
"log_level": "INFO"
}

To stop worrying about your SDcard you could also add this line to /etc/fstab

tmpfs /var/log tmpfs defaults 0 0

Example here:

github.com

j1nx/MycroftOS/blob/master/buildroot-external/rootfs-overlay/etc/fstab#L9


# <file system>	<mount pt>	<type>	<options>	<dump>	<pass>
/dev/root	/		ext2	rw,noauto	0	1
proc		/proc		proc	defaults	0	0
devpts		/dev/pts	devpts	defaults,gid=5,mode=620,ptmxmode=0666	0	0
tmpfs		/dev/shm	tmpfs	mode=0777	0	0
tmpfs		/tmp		tmpfs	mode=1777	0	0
tmpfs		/run		tmpfs	mode=0755,nosuid,nodev	0	0
sysfs		/sys		sysfs	defaults	0	0
tmpfs		/var/log	tmpfs	defaults	0	0
tmpfs		/var/tmp	tmpfs	defaults	0	0
tmpfs		/ramdisk	tmpfs	rw,nodev,nosuid,size=20M	0	0

However then your logs won’t survice a reboot as /var/log will be a tmpfs in memory instead of the SDcard

Wally_Fort · November 13, 2018, 12:51am

I put a file located in /etc/logrotate.d/ to rotate the logs file every day and just keep the last 7 days. Not sure the best place to place the file for others to access it.

watou · November 13, 2018, 8:55am

@Wally_Fort If it’s not too big of a file could you paste it into a reply here? First make a line with three back-ticks like ```, then paste the file contents on lower lines, and then end with a new line with three more back-ticks ``` so you get a separate code block

like this

j1nx · November 13, 2018, 10:54am

If the logs become to lengthy you could always paste them here;

And post the link to it.

Wally_Fort · November 13, 2018, 5:28pm

# rotate mycroft log files.
# located in /etc/logrotate.d/
# use 'su' becuase the log files are owned by pi

su pi pi

# Rotate daily, keep 7 days, copytruncate for active files.
/var/log/mycroft/audio.log {
rotate 7
daily
copytruncate
}

# Rotate daily, keep 7 days, copytruncate for active files.
/var/log/mycroft/bus.log {
rotate 7
daily
copytruncate
}

# Rotate daily, keep 7 days, copytruncate for active files.
/var/log/mycroft/skills.log {
rotate 7
daily
copytruncate
}

# Rotate daily, keep 7 days, copytruncate for active files.
/var/log/mycroft/voice.log {
rotate 7
daily
copytruncate
}