What is Causing the Character "q" To be Typed?

Questions & Suggestions
1

###What is Causing the Character “q” To be Typed?

OK, this is a real mystery. Sometimes when I quit an app (using ⌘Q), the character “q” is typed (or maybe pasted) into the the app that receives focus after the quit.

How can I figure out what is causing this?

I am using only two apps that can produce text expansion:

  1. TextExpander
  2. Keyboard Maestro

My main suspect is TextExpander, but I can’t rule out KM.

The biggest issue is that it does NOT happen 100% of the time, and I can’t nail down the exact steps that will always cause it to happen.

I’ve looked at the log files in Console, but have not been able to spot anything there.

Any and all troubleshooting ideas will be greatly welcomed.

2

To check if it’s caused by a KM macro you’ve created… Next time it occurs, open the KM Editor, select All Macros in the left column, then use View > Sort Macros By > Date Used and you’ll see your macros ordered in the middle column by which are the most recently used. If that doesn’t reveal the source of the issue, you at least know to focus on TextExpander.

3

I have another recent report from a user with this macro:

20170307-164342.png772×434 49.7 KB

And a q being typed occasionally in the next application.

I really have no idea what might be going on - my two guesses would be some weird system bug or some weird interaction on the event queue.

I've never heard of anything like this, so it is very odd to see two reports within a week - sounds like something has changed somewhere.

4

I have the exact same issue. (see below) I assumed it was related to the ‘q’ in the macro trigger I am using. Are you using a macro with a ‘q’ in the trigger as well?

I have a macro that hides an app instead of quitting it. It is triggered by ‘Command-Q’ and types the keystroke 'Command-H’. I have it working for about a dozen apps.

When I quit an app that does NOT have the macro enabled for it, it quits as expected, but then a letter “q” is typed in the next app that becomes active.

When I deactivate the “Hide Not Quit” macros, the apps just quit as expected and no “q” is typed in the next active app.

Sure enough, when I turn the macros back on, “q” is typed in the next active app.

5

I’m not sure if it is related to @JMichaelTX’s issue, but I had a thought on @mikewolf1127’s issue.

Since the trigger is a hot key trigger for Command-Q, when pressed, and you hide the application, that will likely deactivate the macro group. At which point the Command and Q key will still be pressed, but the hot key trigger will be removed. That would be a strange state at that point, the next application will see the Q release event, with the system having ever seen a Q pressed event (because the system captured it for the Command-Q hot key. It’s plausible that that could cause the Q to end up being typed.

If so, changing the hot key trigger to Command-Q released might resolve the issue - whether the delay in responding is perceptible or not depends on how you type the Command-Q.

1 Like
6

My sincere thanks to you guys who responded.

I have definitely narrowed it down to TextExpander.
After I quit TE, I did NOT get any occurrences of this behavior.
As soon as I launched TE, and quit Script Debugger, I got the "q" typed.

I didn't really think it was KM, but I am so relieved to have confirmed it.

Here's the log that TE made. Looks very suspicious, but I don't really understand it.
Anyone else get it?

TE is logging something about "cmd- , q", but what does it mean?

I have just received, and replied to, an issue I filed with TE SmileSoftware Support.
They asked for the log, and I have just sent it to them.

Here's the log, with my annotations.

--- I CLOSED SD6 WINDOW USING CMD-w ---
3/7/17 9:42:07.918 PM TextExpander[47520]: event tap entered with event: 0x7fd2b95b37a0, timestamp: 1C68529B83E28
3/7/17 9:42:07.919 PM TextExpander[47520]: keyLogChars:13 cmd-w, 
3/7/17 9:42:07.919 PM TextExpander[47520]: event tap exited with en event:  0x7fd2b95b37a0

--- I QUIT SD6 (I think) USING CMD-q ---
3/7/17 9:42:32.037 PM TextExpander[47520]: FocusInfo - Detected PID 46948 change via key event 46290
3/7/17 9:42:32.037 PM TextExpander[47520]: event tap entered with event: 0x7fd2be11c5d0, timestamp: 1C68AC74A4EB4
3/7/17 9:42:32.038 PM TextExpander[47520]: keyLogChars(new PID):48 cmd-	, 
3/7/17 9:42:32.038 PM TextExpander[47520]: event tap exited with en event:  0x7fd2be11c5d0
3/7/17 9:42:32.202 PM WindowServer[163]: send_datagram_available_ping: pid 476 failed to act on a ping it dequeued before timing out.

3/7/17 9:42:33.870 PM TextExpander[47520]: event tap entered with event: 0x7fd2be11c5d0, timestamp: 1C68B349CA931
3/7/17 9:42:33.871 PM TextExpander[47520]: keyLogChars:48 cmd-	, 
3/7/17 9:42:33.871 PM TextExpander[47520]: event tap exited with en event:  0x7fd2be11c5d0

3/7/17 9:42:34.534 PM TextExpander[47520]: event tap entered with event: 0x7fd2be218bb0, timestamp: 1C68B5C2EBAB5
3/7/17 9:42:34.535 PM TextExpander[47520]: keyLogChars:48 cmd-	, 
3/7/17 9:42:34.535 PM TextExpander[47520]: event tap exited with en event:  0x7fd2be218bb0
3/7/17 9:42:34.876 PM TextExpander[47520]: event tap entered with event: 0x7fd2be04bfc0, timestamp: 1C68B70915E94
3/7/17 9:42:34.877 PM TextExpander[47520]: keyLogChars:48 cmd-	, 
3/7/17 9:42:34.877 PM TextExpander[47520]: event tap exited with en event:  0x7fd2be04bfc0

3/7/17 9:42:35.198 PM TextExpander[47520]: event tap entered with event: 0x7fd2ba838110, timestamp: 1C68B83C4A425
3/7/17 9:42:35.199 PM TextExpander[47520]: keyLogChars:48 cmd-	, 
3/7/17 9:42:35.199 PM TextExpander[47520]: event tap exited with en event:  0x7fd2ba838110
3/7/17 9:42:35.480 PM TextExpander[47520]: event tap entered with event: 0x7fd2be04bef0, timestamp: 1C68B949233CA
3/7/17 9:42:35.481 PM TextExpander[47520]: keyLogChars:48 cmd-	, 
3/7/17 9:42:35.481 PM TextExpander[47520]: event tap exited with en event:  0x7fd2be04bef0
3/7/17 9:42:35.742 PM TextExpander[47520]: event tap entered with event: 0x7fd2be11c5d0, timestamp: 1C68BA4309532
3/7/17 9:42:35.743 PM TextExpander[47520]: keyLogChars:48 cmd-	, 
3/7/17 9:42:35.743 PM TextExpander[47520]: event tap exited with en event:  0x7fd2be11c5d0
3/7/17 9:42:35.984 PM TextExpander[47520]: event tap entered with event: 0x7fd2be11c5d0, timestamp: 1C68BB29DE597
3/7/17 9:42:35.985 PM TextExpander[47520]: keyLogChars:48 cmd-	, 
3/7/17 9:42:35.985 PM TextExpander[47520]: event tap exited with en event:  0x7fd2be11c5d0

3/7/17 9:42:36.206 PM TextExpander[47520]: event tap entered with event: 0x7fd2be11c5d0, timestamp: 1C68BBFD7DC0D
3/7/17 9:42:36.206 PM TextExpander[47520]: keyLogChars:48 cmd-	, 
3/7/17 9:42:36.207 PM TextExpander[47520]: event tap exited with en event:  0x7fd2be11c5d0
3/7/17 9:42:36.568 PM TextExpander[47520]: event tap entered with event: 0x7fd2be218bb0, timestamp: 1C68BD56DD7B1
3/7/17 9:42:36.569 PM TextExpander[47520]: keyLogChars:48 cmd-	, 
3/7/17 9:42:36.569 PM TextExpander[47520]: event tap exited with en event:  0x7fd2be218bb0

--- 2.5 sec lapse ---

3/7/17 9:42:39.082 PM TextExpander[47520]: event tap entered with event: 0x7fd2be218bb0, timestamp: 1C68C6B459CBC
3/7/17 9:42:39.000 PM syslogd[46]: ASL Sender Statistics
3/7/17 9:42:39.083 PM TextExpander[47520]: keyLogChars:48 cmd-	, 
3/7/17 9:42:39.083 PM TextExpander[47520]: event tap exited with en event:  0x7fd2be218bb0

--- I QUIT SD6 USING CMD-q ---

3/7/17 9:42:43.235 PM TextExpander[47520]: FocusInfo - Detected PID 46290 change via key event 46948
3/7/17 9:42:43.235 PM TextExpander[47520]: event tap entered with event: 0x7fd2b95b37a0, timestamp: 1C68D62C285F0
3/7/17 9:42:43.236 PM TextExpander[47520]: keyLogChars(new PID):12 cmd-q, 
3/7/17 9:42:43.236 PM TextExpander[47520]: event tap exited with en event:  0x7fd2b95b37a0
3/7/17 9:42:43.278 PM WindowServer[163]: send_datagram_available_ping: pid 476 failed to act on a ping it dequeued before timing out.
3/7/17 9:42:43.291 PM TextExpander[47520]: FocusInfo - Detected PID 46948 change via key event 46179
3/7/17 9:42:43.394 PM TextExpander[47520]: event tap entered with event: 0x7fd2be11c5d0, timestamp: 1C68D6C4951B7

--- NOTICE TE LOG OF "12 q" ---
(ASCII "12" is FF)

3/7/17 9:42:43.394 PM TextExpander[47520]: keyLogChars:12 q, 
3/7/17 9:42:43.395 PM TextExpander[47520]: event tap exited with en event:  0x7fd2be11c5d0

--- AFTER I QUIT SD6, BBEDIT WAS ACTIVE ---

3/7/17 9:43:05.339 PM TextExpander[47520]: FocusInfo - Detected PID 46179 change via key event 46290
3/7/17 9:43:05.339 PM TextExpander[47520]: event tap entered with event: 0x7fd2be218bb0, timestamp: 1C6928848A8F3
3/7/17 9:43:05.340 PM TextExpander[47520]: keyLogChars(new PID):48 cmd-	, q
3/7/17 9:43:05.340 PM TextExpander[47520]: event tap exited with en event:  0x7fd2be218bb0
3/7/17 9:43:05.480 PM WindowServer[163]: send_datagram_available_ping: pid 476 failed to act on a ping it dequeued before timing out.

3/7/17 9:43:06.990 PM TextExpander[47520]: event tap entered with event: 0x7fd2be11c5d0, timestamp: 1C692EAC0B3EE
3/7/17 9:43:06.991 PM TextExpander[47520]: keyLogChars:48 cmd-	, 
3/7/17 9:43:06.991 PM TextExpander[47520]: event tap exited with en event:  0x7fd2be11c5d0

3/7/17 9:43:07.212 PM TextExpander[47520]: event tap entered with event: 0x7fd2be04bef0, timestamp: 1C692F7F85F9A
3/7/17 9:43:07.212 PM TextExpander[47520]: keyLogChars:48 cmd-	, 
3/7/17 9:43:07.213 PM TextExpander[47520]: event tap exited with en event:  0x7fd2be04bef0
3/7/17 9:43:07.474 PM TextExpander[47520]: event tap entered with event: 0x7fd2be11c5d0, timestamp: 1C69307995958
3/7/17 9:43:07.475 PM TextExpander[47520]: keyLogChars:48 cmd-	, 
3/7/17 9:43:07.475 PM TextExpander[47520]: event tap exited with en event:  0x7fd2be11c5d0

--- I MADE TE FRONTMOST, AND THEN QUIT USING CMD-q ---

3/7/17 9:43:07.811 PM TextExpander[47520]: App becoming active
3/7/17 9:43:07.811 PM TextExpander[47520]: Temporarily disable event taps: disable now - 1
3/7/17 9:43:10.763 PM TextExpander[47520]: Disable keyDown event tap
3/7/17 9:43:10.763 PM TextExpander[47520]: Disable mouseDown event tap
3/7/17 9:43:10.764 PM TextExpander[47520]: cleanUp
3/7/17 9:43:10.764 PM TextExpander[47520]: bye

--- I THEN OPENED CONSOLE LOG ---
7

I guess to really confirm this would be to quit Keyboard Maestro and Keyboard Maestro Engine and verify you can still make it happen.

8

Good point, Peter.

Actually, I just tried this test:

  1. Quit TextExpander (TE).
  2. Open BBEdit
  3. Open SD6 with file
  4. Close SD6 window
  5. Quit SD6
  6. BBEdit auto-activates
  7. "q" is typed into BBEdit

So it now appears that KM is causing this strange behavior.

I also got a reply from SmileSupport who reviewed the TE logs during the last occurrence. They said they see nothing in the logs that would indicate TE caused this issue.

I have reviewed the log (below) and the Macro (below), and I can NOT find anything that would type/paste a "q".

Any ideas?

Here's the KME log during this time:

2017-03-08 15:17:59 Execute macro ‘@DATE  Type ICO Date/Time’ from trigger The exact case string ‘;dt.i«Space»’ is typed (then deleted)

2017-03-08 15:18:07 Execute macro ‘@MOU Move Mouse to FrontMost Window When Window Changes’ from trigger tFocusedWindowFocusedWindowChanges
2017-03-08 15:18:10 Execute macro ‘@MOU Move Mouse to FrontMost Window When Window Changes’ from trigger tFocusedWindowFocusedWindowChanges
2017-03-08 15:18:14 Execute macro ‘@MOU Move Mouse to FrontMost Window When Window Changes’ from trigger tFocusedWindowFocusedWindowChanges

--- BBEDIT:  TYPE D/T VIA KM MACRO ---

2017-03-08 15:18:42 Execute macro ‘@DATE  Type ICO Date/Time’ from trigger The exact case string ‘;dt.i«Space»’ is typed (then deleted)

--- LAUNCH SD6 VIA LB ---

2017-03-08 15:18:55 Execute macro ‘@MOU Move Mouse to FrontMost Window When Window Changes’ from trigger tFocusedWindowFocusedWindowChanges
2017-03-08 15:18:55 Running application query took a while (15226 us)
2017-03-08 15:19:00 Running application query took a while (3284 us)

--- SD6:  CLOSE WINDOW AND QUIT ---

2017-03-08 15:19:00 Execute macro ‘@MOU Move Mouse to FrontMost Window When Window Changes’ from trigger tFocusedWindowFocusedWindowChanges

--- BBEDIT:  AUTO ACTIVATE, "q" is typed into BBEDIT

--- STOP KME VIA STATUS MENU ---

2017-03-08 15:19:16 Stopping web server
2017-03-08 15:19:16 Engine Quitting

Here's the KM Macro that ran AFTER I quit SD6:
Note that I have DISABLED the Macro prior to upload.

##Macro Library   @MOU Move Mouse to FrontMost Window When Window Changes


####DOWNLOAD:
<a class="attachment" href="/uploads/default/original/2X/7/784b1ca6a446fd8ddd679412c7af16209de674ea.kmmacros">@MOU Move Mouse to FrontMost Window When Window Changes.kmmacros</a> (176 KB)

---

###ReleaseNotes

Author.@JMichaelTX

**PURPOSE:**

* **Move the Mouse to Follow Activation of Different Window**

**HOW TO USE:**

1. **ENABLE MACRO**

2. Macro Group -- Put in a Global Macro Group, available to ALL Apps

3. Activate a Different Window (other than by Mouse Click)
  * For Each App, you will be prompted to Set Mouse Position for Preset Mode.
    * You can set Mouse Position Relative to any corner of the Window
    * You can choose "None" -- Mouse will NOT be moved when in Preset Mode
    * You can choose "Off" -- Mouse will NOT be moved in either Preset or Last Mode

4. Toggle MMF_Method ([PRESET] / [LAST]) -- Trigger maco by hot key ^⌥END

5. Toggle Macro On/Off -- Trigger Macro by Name
  * Similar to actual Enable/Disable, except the first few Macro Actions still run
  * Then Macro is Canceled

6. Set PRESET Mouse Position for an App -- Trigger macro by ^⌥HOME
  * This actually triggers a Sub-Macro:  "@MOU Update List of PRESET Mouse Positions Relative to Window"

WHAT IT DOES:

1. NORMAL CASE
**IF a Different Window is Activated by any Method OTHER than Mouse Click**
  * IF DND_MMF__Method = 
    * "[PRESET]"
        * Move Mouse to Preset Location for that App, unless App Setting is "None" or "Off"
    * "[LAST]"
        * Move Mouse to Last Location for that App, unless App Setting is "Off"

2. EXCEPTIONS
  * IF Mouse MoveTo Position is outside of Window, set to Center of Window
  * Window Activated by Mouse Click -- Do NOT Move Mouse
  * Macro is Off (DND_MMF__On = FALSE) -- Do NOT Move Mouse
  * Macro is Canceled for Special Cases 
(see Comment "CANCEL FOR SPECIAL CASES")
    * Non-standard Window
    * Window changes too fast
    * Certain Windows for Google Chrome
    * Window is In-Process of being Manually Moved/Resized

TAGS:  

USER SETTINGS:

  * Any Action in magenta color is designed to be changed by end-user
  * This macro uses Google Search and Google Chrome, but can be easily changed

ACTION COLOR CODES

  * To facilitate the reading, customizing, and maintenance of this macro,
      key Actions are colored as follows:
  * GREEN      -- Key Comments designed to highlight main sections of macro
  * MAGENTA -- Actions designed to be customized by user
  * YELLOW   -- Primary Actions (usually the main purpose of the macro)
  * ORANGE  -- Actions that permanently destroy Varibles or Clipboards

REQUIRES:  
(1)  Keyboard Maestro Ver 7.3+
(2)  Yosemite (10.10.5)+


---

<img src="/uploads/default/original/2X/1/1b07be8e2f3ee0e83c4a38c2a81fa714a9b26886.png" width="628" height="1664">
9

Does this issue remain if the macro is disabled?

If it does continue when Keyboard Maestro is not running any macro, then the issues is likely something else.

If it only happens with the macro triggering, then you will need to try to reduce the occurrence to a minimal macro. Does it happen if the macro triggers but has no actions at all? All disabled? Then enable each action one after the other until you find where something goes wrong.

If the issue is consistent, this is not too hard. If the issue is sporadic, then it will be more challenging to narrow down.

10

Thanks for all the great questions and suggestions, Peter.

###The saga continues.

  1. It is NOT either KM nor TE.
  2. Ran numerous tests last night without either KM nor TE running, and had numerous occurrences.
  3. BUT, after running 6 tests today, using SD6 and Script Editor (3 tests each), did NOT have any occurrences.
  4. 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.
11

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.

1 Like
12

Boot into safe mode and run Onyx maintenance.

Create a new user and try to reproduce

1 Like
13

OK, thanks for sharing that. Would you mind sharing what you found as the "third ingredient"?

If it is not too laborious (for you to type), could you share the process you used to identify the mystery ingredient?

Many thanks for your help, Tom.

14

Thanks for the suggestions. I'll give it a shot.

15

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
16

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’.

17

Good question.

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?

Many thanks for your analysis and thoughts.

18

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?

Don't change too many things at once.

1 Like
19

done.

I'm not running Alfred, but I am running LB.
After KM, it is my most used tool.
If I get another occurrence, I'll turn off LB, and extensively test.

20
  1. Boot into safe mode.
  2. 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.
  3. If you are unable to reproduce the issue then you have a high probability that a third thing is involved.
  4. Reboot in normal mode.
  5. 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.
  6. If you can reproduce the issue again, then…
  7. …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.

1 Like