EDSM Plugin sent wrong credit balance when switching accounts

[jmbox]

I have 2 Elite accounts, and 2 EDSM accounts, with separate keys set correctly in EDMC.

Now I've switched many times without anything untoward happening that I've noticed. EDSM records jumps and other Badge earning achievements correctly per account.

Today, running EDMC 5.0.4+2ba8cf1, when switching from account 1 to account 2, it sent the credit balance from account 1 to EDSM for account 2.

Account 1 has 5.5bn credits. Account 2 has 1.7bn credits. EDSM awarded the 4bn+ Cr Badge to Account 2.

Ath suggested "we can at least add logging to state which Journal Commander we're sending for, and to which EDSM account."

[jmbox]

Switching back from account 2 to account 1. EDSM has recorded account 2's location into account 1, earning a distance badge for account 1

[Athanasius]

1. Open regedit.exe
2. Navigate to Computer\HKEY_CURRENT_USER\SOFTWARE\Marginal\EDMarketConnector (you can select the text for the current key/location and paste this one over then hit return).
3. Paste here the contents of the cmdrs and edsm_cmdrs keys.
4. Then also check, do not paste here, the contents of the edsm_apikeys key, checking that it's in the correct order. Due to this being a REG_MULTI_SZ string, where multiple strings are concatenated with a NUL \0 character inbetween, it will look like it's just the two mashed together, but you can check the order.

[Athanasius]

Logging in to my steam account (main is frontier), when I hadn't yet added EDSM:

2021-06-04 10:07:00.224 - ERROR - 4824:13092:13092 plug.Plugin.get_prefs:113: Failed for Plugin "EDSM"
Traceback (most recent call last):
  File "C:\Users\Athan\Documents\Devel\EDMarketConnector\plug.py", line 108, in get_prefs
    frame = plugin_prefs(parent, cmdr, is_beta)
  File "C:\Users\Athan\Documents\Devel\EDMarketConnector\plugins\edsm.py", line 235, in plugin_prefs
    prefs_cmdr_changed(cmdr, is_beta)
  File "C:\Users\Athan\Documents\Devel\EDMarketConnector\plugins\edsm.py", line 249, in prefs_cmdr_changed
    cred = credentials(cmdr)
  File "C:\Users\Athan\Documents\Devel\EDMarketConnector\plugins\edsm.py", line 334, in credentials
    return (config.get_list('edsm_usernames')[idx], config.get_list('edsm_apikeys')[idx])
IndexError: list index out of range

[Athanasius]

The precise sequence for the above was:

1. Check registry for the comment further above, realise I never added this alt account to EDSM.
2. Fire up EDMC (the inara API branch, but won't affect this).
3. Fire up steam and login to the game.
4. Perform Frontier Auth.
5. Open EDMC Settings to set the EDSM API key.
6. No EDSM tab, checck EDMC logs.

[Athanasius]

@jmbox given the bug I found and fixed... could you please supply us with both plain and debug log files as per https://github.com/EDCD/EDMarketConnector/wiki/Troubleshooting#debug-log-files

[jmbox]

Both cmdrs and edsm_cmdrs contain:
Sidewinder40 Sidewinder42

edsm_apikeys has the keys in the correct order

[jmbox]

EDMarketConnector-debug.log
EDMarketConnector.log

[Athanasius]

Some notes on the code flow:

1. The commander name used starts out in monitor.cmdr - EDMarketConnector.py call of plug.notify_journal_entry().
2. That then passes it unaltered to the plugin journal_entry().
3. It is then used, unaltered, to create the (cmdr, entry) tuple that is appended to the work queue.
4. That is then pulled off the queue in plugins/edsm.py:worker(). (cmdr, entry) = item.
5. That then gets used in creds = credentials(cmdr).
6. username, apikey = creds.
7. 'commanderName': username.encode('utf-8')

Does EDSM actually check that the commanderName is correct for the given API Key ?

[chennin]

This has also been happening to me. Note for @jmbox: this has ALSO been confusing my flight log entries in EDSM, and I've had to delete some of them.

EDMC versions - 5.1.1, now 5.1.2. Windows 10. One copy of EDMC running at a time. I don't usually restart EDMC unless I'm changing a plugin. No other sending tools.

Picture

I got the most recent one with EDMC debug logging on, unfortunately not with debug-sender on.

In the registry, both cmdrs and edsm_cmdrs contain the following, and edsm_apikeys has the keys in the correct order.

Winter Ihernglass
Floor Jansen

I'll attach both of today's Journals, they're short:

Journal.210803080400.01.log
Journal.210803114432.01.log

Here's EDMarketConnector.log:

EDMarketConnector.log

And here's EDMarketConnector-debug.log (I haven't restarted it in a few days, but it rotated):

EDMarketConnector-debug.log

[chennin]

OK! I logged an incorrect EDSM request via --debug-sender edsm. It has commanderName=Winter+Ihernglass and the correct api key for Winter, followed by events that have wrong data, in the same request:

event=LoadGame
Commander=Floor Jansen
ShipName=ADVENT OF MAY (wrong for Winter)
Credits=3433782854 (wrong for Winter)

event=Location
StarSystem=Hypuae Bra RX-L d7-2 (wrong for Winter)

bad-edsm-request.txt

[Athanasius]

@chennin how much of the data is wrong in that ?

Materials we know a way for it to be wrong. But if anything else is we need to know.

[Athanasius]

Oh, hang on... if it's using the cmdr name/apikey from the first event it processes to be sent out, then the mis-treatment of Materials could mean it uses the previous cmdr for all the events sent in this batch, so it could indeed be affecting everything else, including LoadGame and its Credits value.

[Athanasius]

Oh, hang on... if it's using the cmdr name/apikey from the first event it processes to be sent out, then the mis-treatment of Materials could mean it uses the previous cmdr for all the events sent in this batch, so it could indeed be affecting everything else, including LoadGame and its Credits value.

No, scratch that.

The cmdr used in the actual send to EDSM is from whatever monitor.cmdr was when the event that caused should_send() to return True happened.

For login I think it's the Cargo event that will first should_send() == True, which is well after the LoadGame event, which would have set monitor.cmdr correctly.

So only the Materials, Rank, Progress, Reputation, EngineerProgress and SquadronStartup events could possibly have the wrong (new) cmdr name/apikey erroneously used in this scenario. This doesn't explain bad Credits balances.

[chennin]

@chennin how much of the data is wrong in that ?

Materials we know a way for it to be wrong. But if anything else is we need to know.

Given the CommanderName=Winter+Ihernglass, every event EXCEPT the second Materials event is for Floor Jansen and is wrong.

[Athanasius]

Ugh, yeah, I'm just going to have to sort out using my main and steam alt accounts to test this myself to be sure of what's going on.

[Athanasius]

There's a fix for this in develop now. I'll look at putting out a 5.1.3-beta1 tomorrow for those affected to test it.

[Athanasius]

@jmbox @chennin Please test https://github.com/EDCD/EDMarketConnector/releases/tag/Release%2F5.1.3-beta1 - it should fix the problem.

[chennin]

I tried several times with 5.1.3b1 and wasn't able to replicate the problem

[Athanasius]

I tried several times with 5.1.3b1 and wasn't able to replicate the problem

And the data sent to EDSM on any account looks correct and complete otherwise ?

[chennin]

Correct, there wasn't any confusion of credits or ships

[Athanasius]

Correct, there wasn't any confusion of credits or ships

OK, I''ll consider this issue closed then. The fix will be in 5.1.3 which should be out Monday latest (I want to check if anything else should go into it).

[Athanasius]

@chennin note that you won't get offered the update from 5.1.3-beta1 to 5.1.3 due to some crapness in how that check is done. So grab 5.1.3 from https://github.com/EDCD/EDMarketConnector/releases/tag/Release%2F5.1.3 and install it manually.