Thanks for all the great questions and suggestions, Peter.
###The saga continues.
It is NOT either KM nor TE.
Ran numerous tests last night without either KM nor TE running, and had numerous occurrences.
BUT, after running 6 tests today, using SD6 and Script Editor (3 tests each), did NOT have any occurrences.
This is so inconsistent and frustrating!
After having a restart, and quit both TE and KME, I ran some more tests with BBEdit and mostly SD6, but also Console.
Unfortunately NOT 100% consistent.
But fairly often with SD6, with I quit SD6 I'd get a "q" in BBEdit.
Once or twice when I quit Console, I got a "Q" -- first time I've seen a capital "Q".
I kept Activity Monitor open, trying to observe anything consistent or suspicious when the "q" was typed. I didn't see anything, but here's a screenshot immediately after I quit SD6 and a "q" was typed into BBEdit:
###Activity Monitor after Occurrence
###Console Log (All Messages) after Occurrence
3/9/17 12:11:18.729 AM identityservicesd[294]: <IMMacNotificationCenterManager: 0x7fa5fbe6c200>: Updating enabled: YES (Topics: (
"com.apple.madrid"
))
3/9/17 12:12:09.000 AM syslogd[46]: ASL Sender Statistics
3/9/17 12:12:10.000 AM kernel[0]: Script Debugger[989] triggered unnest of range 0x7fff8a200000->0x7fff8a400000 of DYLD shared region in VM map 0xff1cf6c0c0c472c7. While not abnormal for debuggers, this increases system memory footprint until the target exits.
3/9/17 12:12:22.000 AM kernel[0]: Script Debugger[993] triggered unnest of range 0x7fff8a200000->0x7fff8a400000 of DYLD shared region in VM map 0xff1cf6c0c0c472c7. While not abnormal for debuggers, this increases system memory footprint until the target exits.
q --- was typed just before 00:12:30.1 ---
3/9/17 12:12:38.955 AM imagent[343]: <IMMacNotificationCenterManager: 0x7ffdd0504910>: notification observer: com.apple.FaceTime notification: __CFNotification 0x7ffdd0405a50 {name = _NSDoNotDisturbEnabledNotification}
3/9/17 12:12:38.955 AM identityservicesd[294]: <IMMacNotificationCenterManager: 0x7fa5fbe6c200>: notification observer: com.apple.iChat notification: __CFNotification 0x7fa5fbf12210 {name = _NSDoNotDisturbEnabledNotification}
3/9/17 12:12:38.978 AM identityservicesd[294]: <IMMacNotificationCenterManager: 0x7fa5fbe6c200>: NC Disabled: NO
3/9/17 12:12:38.978 AM imagent[343]: <IMMacNotificationCenterManager: 0x7ffdd0504910>: NC Disabled: NO
3/9/17 12:12:38.986 AM identityservicesd[294]: <IMMacNotificationCenterManager: 0x7fa5fbe6c200>: DND Enabled: YES
3/9/17 12:12:38.986 AM imagent[343]: <IMMacNotificationCenterManager: 0x7ffdd0504910>: DND Enabled: YES
3/9/17 12:12:38.986 AM identityservicesd[294]: <IMMacNotificationCenterManager: 0x7fa5fbe6c200>: Updating enabled: NO (Topics: (
))
3/9/17 12:12:38.986 AM imagent[343]: <IMMacNotificationCenterManager: 0x7ffdd0504910>: Updating enabled: NO (Topics: (
))
3/9/17 12:12:38.986 AM identityservicesd[294]: <IMMacNotificationCenterManager: 0x7fa5fbc38ae0>: notification observer: com.apple.iChat notification: __CFNotification 0x7fa5fbf16a30 {name = _NSDoNotDisturbEnabledNotification}
3/9/17 12:12:38.991 AM identityservicesd[294]: <IMMacNotificationCenterManager: 0x7fa5fbc38ae0>: NC Disabled: NO
3/9/17 12:12:38.995 AM identityservicesd[294]: <IMMacNotificationCenterManager: 0x7fa5fbc38ae0>: DND Enabled: YES
3/9/17 12:12:38.995 AM identityservicesd[294]: <IMMacNotificationCenterManager: 0x7fa5fbc38ae0>: Updating enabled: NO (Topics: (
))
3/9/17 12:12:47.160 AM identityservicesd[294]: <IMMacNotificationCenterManager: 0x7fa5fbc38ae0>: notification observer: com.apple.iChat notification: __CFNotification 0x7fa5fdb34c20 {name = _NSDoNotDisturbDisabledNotification}
If anyone sees anything the least bit suspicious, please let me know.
There might be third component involved which you are not thinking of at the moment.
Recently I had unexplainable mouse input issues in BBEdit, but only in conjunction with the Apple mouse, and not always and not since ever. Eventually, after booting in safe mode I learned that there was a third ingredient, responsible for the issue.
OK, just happened again.
This time, I have both KM and TE running.
TE provides an interesting log of keystrokes.
Until I can test in SAFE mode, I'll just post this, in case anyone is interested and would like to comment.
###System Log After Occurrence of "q"
Happened when I QUIT SD6, and BBEdit was auto-activated.
===== FROM SYSTEM LOG ========
--- NEXT MUST BE WHEN I CLOSED THE SD WINDOW USING ⌘W ---
3/9/17 4:14:44.449 PM TextExpander[1908]: keyLogChars(new PID):13 cmd-w,
3/9/17 4:14:44.449 PM TextExpander[1908]: event tap exited with en event: 0x7fc534a12550
3/9/17 4:14:45.788 PM TextExpander[1908]: event tap entered with event: 0x7fc5370aaa90, timestamp: E657AEA29DF
--- NEXT MUST BE WHEN I QUIT SD USING ⌘Q ---
3/9/17 4:14:45.788 PM TextExpander[1908]: keyLogChars:12 cmd-q,
3/9/17 4:14:45.788 PM TextExpander[1908]: event tap exited with en event: 0x7fc5370aaa90
3/9/17 4:14:45.826 PM WindowServer[182]: CGXGetConnectionProperty: Invalid connection 159379
3/9/17 4:14:45.826 PM WindowServer[182]: CGXGetConnectionProperty: Invalid connection 159379
3/9/17 4:14:45.831 PM TextExpander[1908]: FocusInfo - Detected PID 2033 change via key event 1917
3/9/17 4:14:45.928 PM TextExpander[1908]: event tap entered with event: 0x7fc53486a610, timestamp: E6583416BF2
--- NOW TE IS RECORDING A KEYSTROKE OF "q" -- where does it come from? ---
3/9/17 4:14:45.929 PM TextExpander[1908]: keyLogChars:12 q,
3/9/17 4:14:45.930 PM TextExpander[1908]: event tap exited with en event: 0x7fc53486a610
3/9/17 4:15:01.203 PM SpotlightNetHelper[425]: [SLSUGGESTIONS] Location managed failed with error Error Domain=kCLErrorDomain Code=0 "(null)"
3/9/17 4:15:01.621 PM TextExpander[1908]: FocusInfo - Detected PID 1917 change via key event 409
3/9/17 4:15:03.080 PM TextExpander[1908]: event tap entered with event: 0x7fc532429ac0, timestamp: E69819ECC65
3/9/17 4:15:03.081 PM TextExpander[1908]: keyLogChars:8 c,
3/9/17 4:15:03.082 PM TextExpander[1908]: event tap exited with en event: 0x7fc532429ac0
3/9/17 4:15:03.126 PM Spotlight[409]: XPC connection was invalidated
3/9/17 4:15:03.140 PM TextExpander[1908]: event tap entered with event: 0x7fc53717dc40, timestamp: E6985310059
3/9/17 4:15:03.140 PM TextExpander[1908]: keyLogChars:31 o, c
3/9/17 4:15:03.141 PM TextExpander[1908]: event tap exited with en event: 0x7fc53717dc40
--- THE NEXT BLOCK SEEMS IRRELAVENT ---
3/9/17 4:15:03.149 PM SpotlightNetHelper[425]: CFPasteboardRef CFPasteboardCreate(CFAllocatorRef, CFStringRef) : failed to create global data
3/9/17 4:15:03.151 PM SpotlightNetHelper[425]: CFPasteboardRef CFPasteboardCreate(CFAllocatorRef, CFStringRef) : failed to create global data
3/9/17 4:15:03.154 PM SpotlightNetHelper[425]: CFPasteboardRef CFPasteboardCreate(CFAllocatorRef, CFStringRef) : failed to create global data
3/9/17 4:15:03.156 PM SpotlightNetHelper[425]: CFPasteboardRef CFPasteboardCreate(CFAllocatorRef, CFStringRef) : failed to create global data
3/9/17 4:15:03.157 PM Spotlight[409]: XPC connection was invalidated
--- DELETE 26 LINES FROM THE LOG OF THE SAME ---
3/9/17 4:15:03.158 PM SpotlightNetHelper[425]: CFPasteboardRef CFPasteboardCreate(CFAllocatorRef, CFStringRef) : failed to create global data
--- OPEN CONSOLE USING LAUNCHBAR (LB) ---
3/9/17 4:15:03.242 PM TextExpander[1908]: event tap entered with event: 0x7fc532429ac0, timestamp: E698B44CC6F
3/9/17 4:15:03.242 PM TextExpander[1908]: keyLogChars:45 n, co
3/9/17 4:15:03.243 PM TextExpander[1908]: event tap exited with en event: 0x7fc532429ac0
3/9/17 4:15:03.255 PM Spotlight[409]: XPC connection was invalidated
3/9/17 4:15:03.374 PM sandboxd[370]: ([425]) SpotlightNetHelp(425) deny file-read-data /private/var/folders/_2/7b0tgl916vg3ft82hgl011vm0000gn/C/com.apple.IntlDataCache.le
3/9/17 4:15:03.942 PM TextExpander[1908]: event tap entered with event: 0x7fc534fc7e90, timestamp: E69B5009361
3/9/17 4:15:03.942 PM TextExpander[1908]: keyLogChars:36
, con
3/9/17 4:15:03.943 PM TextExpander[1908]: event tap exited with en event: 0x7fc534fc7e90
3/9/17 4:15:04.080 PM Console[2109]: Failed to connect (_consoleX) outlet from (NSApplication) to (ConsoleX): missing setter or instance variable
3/9/17 4:15:05.000 PM kernel[0]: Console[2109] triggered unnest of range 0x7fff8a200000->0x7fff8a400000 of DYLD shared region in VM map 0xff1cf6c0d98c26a7. While not abnormal for debuggers, this increases system memory footprint until the target exits.
3/9/17 4:15:18.203 PM SpotlightNetHelper[425]: tcp_connection_tls_session_error_callback_imp 20 __tcp_connection_tls_session_callback_write_block_invoke.434 error 22
3/9/17 4:16:32.000 PM syslogd[46]: ASL Sender Statistics
Maybe a mis-firing service? A bad keyboard or one going bad?
If it’s always ‘q’ and occurs after ⌘Q, then the ‘q’ in that command might be getting trapped and echoed back by whatever it is that’s listening. Or a keyboard that occasional sends ‘qq’ instead of ‘q’.
I suspect the TE log entries are a red herring – TE is just going “whatever” when it sees the ‘q’.
Just tested in BBEdit.
The delay until repeat was a bit short, so I made it very long.
So now it has to be down about 1.5 sec before the repeat begins.
Did not see any signs of a sticking key, but I'll give my KB a thorough cleaning shortly.
OK, I'll bite. Can you give me an example? Not sure what it would be.
Bingo! The ONLY time I've seen this happen is AFTER I've typed a ⌘Q (but NOT always).
Since it happens when both KM and TE are NOT running, I'm at a loss as to what the "whatever it is that's listening" could possibly be. Any ideas?
Well, I'd start by turning off all the text services (System Preferences > Keyboard > Shortcuts > Services > Text) and looking for a repeat of the problem. If you are error free, then turn the services on again one by one.
Another tack -- are you running LaunchBar or Alfred? Maybe disable them?
In safe mode, try hard to reproduce the issue. With “hard” I mean: if the issue normally occurs every 1 out of 10 I would try it at least 30 times.
If you are unable to reproduce the issue then you have a high probability that a third thing is involved.
Reboot in normal mode.
Try again to reproduce it. Why again? Safe mode does not only deactivate processes and extensions, it also cleans system caches – which is a persistent change.
If you can reproduce the issue again, then…
…you have to find the culprit by elimination (unfortunately; but at least you know there is something more involved):
If you have another Mac try it there. Depending on the outcome, find out which processes are running only on the one Mac, or which processes are running on both Macs.
I you don’t have another Mac, successively deactivate groups of running processes and check again.
Intuition might help, but don’t rely on it.
I know, with intermittent issues, like in your case, the elimination process can be very tedious. That’s why Safe mode is so incredibly useful: if in safe mode the issue occurs also, then you can most likely save yourself the whole hassle of eliminating other processes.
In my case it was Yoink. But my issue was a mouse selection and clicking issue, nothing keyboard-related. So I don’t think this will really help here.
Edit:
FWIW, on my machine I’m unable to reproduce your issue. Tried it 20 times or so with BBEdit and SD6, with and without your macro.
Edit II:
You don’t happen to have Karabiner installed, do you? If the issue does not occur in safe mode, then Karabiner would be the first thing I’d try to eliminate.
I would suggest going about the above from a different angle. Create a new user account and re-add processes one at a time, followed by extensive testing before adding another process.
Prior to that, though, a hardware issue could be the source of the problem. Using another keyboard is a better test than cleaning the current one.
With intermittent issues this can take very much time, even more than the procedure proposed above. And the point of doing the safe boot test as first measure is to see if third-party processes are involved at all. Otherwise you might search for things that don’t exist.
Sounds logical, but I would always make the safe boot test first. Then – if the issue persists – the keyboard would be the first thing to check.
The reason is: there can be hardware and software factors involved. For example my above mentioned mouse input issue had two software factors (BBEdit, Yoink) and one hardware factor (Apple mouse). If I had never made the safe boot test I would have blamed the poor Apple mouse for the rest of my time (since the problem did go away when using another mouse).
Note I said nothing about doing any of my suggested steps before your prior suggestion of doing a safe boot. That's why the part of your post I quoted was only the suggestions which came after you recommended a safe boot. I know there are users here who have third-party software which may install files to /Library (e.g., Karabiner), and I know that a safe boot eliminates such software as possible causes unlike the possible issues a new user account could reveal.
So you have the macro triggering after the Command-Q is released, and you’re still getting a “q” in the next application?
Well, beats the heck out of me. Something must be grabbing stuff off the event queue and putting it back on later - which is a terrible thing to do and always leads to bad behaviour.
I've been wrong before about the cause, but early indicators are that the Logitech Control Center Daemon (LCC) is the cause of the mysterious "q".
After I uninstalled the LCC and did a restart, I have been unable to reproduce the "q" issue.
Also of note, I created a KM macro, triggered by ⌃X to QUIT Script Debugger using the menu. Using this macro, I very quickly got a "x" being typed into BBEdit after SD quit.
I've now (after the LCC removal) ran about 15 tests, with no "q" and no "x". Previously I would get at least one "q" within 10 tests.
I was concerned that my Logitech K750 keyboard and M570 Trackball might stop working properly. And, I did have one issue: The custom keycodes I had associated with my Trackball Back/Forward buttons quit working.
But KM to the Rescue!
The KM Macro where that I had triggered with these codes easily allowed me to add another trigger: "USB Receiver Button 4" and "... 5"
So, for now, all is good. I still need to be observant for while longer to see if the "q" issue has gone away.
My undying gratitude to all of you that offered troubleshooting ideas. I think they all were good ideas. If removal of the LCC does not solve my problem, then I will definitely be using your suggestions.
