Bug Debug log, and general issues with r26279

M

Magus_Prime

Well-known member
With r26279 I tried to log in three times and each time it failed.

Tried logging in directly to KoL from the browser and was able to do so.

Reverted to r26278 and was able to log in immediately. Enabled debug mode and tried again with r26279. I then disabled debug mode and tried again. Was able to log in but while it launched the relay browser, it failed to load the relay browser frames. It hit the browser refresh button and it loaded the frames but generated a debug log.

I'm attaching the "loading the relay browser" debug log but, if there is interest I will load the 1-meg "logging in" debug log.

For now I'm reverting to r26278.
 

Attachments

  • DEBUG_20220302-1.txt
    3.2 KB · Views: 3
M

Magus_Prime

Well-known member
Here you go. It was too large to attach so I had to zip it first.
 

Attachments

  • DEBUG_20220302.zip
    194.8 KB · Views: 3
Veracity

Veracity

Developer
Staff member
"With r26279 I tried to log in three times and each time it failed."
Failed, how? What did it say?

I looked at your login DEBUG log. It logged in successfully.
Ending with this:

Code: 
Loading window: AdventureFrame
Loading window: CommandDisplayFrame
Loading window: MallSearchFrame
Loading window: GearChangeFrame
Loading window: SkillBuffFrame
2 days until Arrrbor Day, Muscle bonus today and yesterday.
7548 prices updated from https://kolmafia.us/scripts/updateprices.php?action=getmap

> debug off

r26279 deals with the MallPriceDatabase - which was the last thing in that part of the DEBUG log. It accesses the database using a different (more modern) HTTP client than other requests within KoLmafia use.

Immediately following the login, there was a stack trace.

Code: 
class java.net.ConnectException: Connection timed out: connect
java.net.ConnectException: Connection timed out: connect
    at java.base/sun.nio.ch.Net.connect0(Native Method)
    at java.base/sun.nio.ch.Net.connect(Net.java:579)
    at java.base/sun.nio.ch.Net.connect(Net.java:568)
    at java.base/sun.nio.ch.NioSocketImpl.connect(NioSocketImpl.java:588)
    at java.base/java.net.Socket.connect(Socket.java:633)
    at java.base/java.net.Socket.connect(Socket.java:583)
    at java.base/sun.net.NetworkClient.doConnect(NetworkClient.java:183)
    at java.base/sun.net.www.http.HttpClient.openServer(HttpClient.java:498)
    at java.base/sun.net.www.http.HttpClient.openServer(HttpClient.java:603)
    at java.base/sun.net.www.http.HttpClient.<init>(HttpClient.java:246)
    at java.base/sun.net.www.http.HttpClient.New(HttpClient.java:351)
    at java.base/sun.net.www.http.HttpClient.New(HttpClient.java:373)
    at java.base/sun.net.www.protocol.http.HttpURLConnection.getNewHttpClient(HttpURLConnection.java:1309)
    at java.base/sun.net.www.protocol.http.HttpURLConnection.plainConnect0(HttpURLConnection.java:1242)
    at java.base/sun.net.www.protocol.http.HttpURLConnection.plainConnect(HttpURLConnection.java:1128)
    at java.base/sun.net.www.protocol.http.HttpURLConnection.connect(HttpURLConnection.java:1057)
    at java.base/sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1665)
    at java.base/sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1589)
    at java.base/java.net.HttpURLConnection.getResponseCode(HttpURLConnection.java:529)
    at net.sourceforge.kolmafia.utilities.FileUtilities.getInputStreamFromConnection(FileUtilities.java:202)
    at net.sourceforge.kolmafia.utilities.FileUtilities.downloadFile(FileUtilities.java:288)
    at net.sourceforge.kolmafia.request.RelayRequest.sendLocalFile(RelayRequest.java:679)
    at net.sourceforge.kolmafia.request.RelayRequest.handleSimple(RelayRequest.java:3125)
    at net.sourceforge.kolmafia.request.RelayRequest.run(RelayRequest.java:3140)
    at net.sourceforge.kolmafia.RequestThread.postRequest(RequestThread.java:243)
    at net.sourceforge.kolmafia.RequestThread.postRequest(RequestThread.java:208)
    at net.sourceforge.kolmafia.webui.RelayAgent.readServerResponse(RelayAgent.java:455)
    at net.sourceforge.kolmafia.webui.RelayAgent.performRelay(RelayAgent.java:103)
    at net.sourceforge.kolmafia.webui.RelayAgent.run(RelayAgent.java:82)
That was using the older style of HTTP connection.

Note that none of this happens to me, using the same version of KoLmafia. It logs in, I can open the Relay Browser. I can log out. It fetches and updates the mall price database.

I'll defer to Ryo Sangnoir. :)
 
M

Magus_Prime

Well-known member
By failed I mean that when I pressed the "Login" button after KoLmafia loaded the main window never loaded and, after, approximately, five to ten seconds the window returned to the state in which it was when it loaded. The main window never loaded and the status messages in the space indicated:

1646234638571.png

Seemed to indicate that the login did not complete. I don't remember the exact messages that appeared and they did not appear in the session log.
 
R

Ryo_Sangnoir

Developer
Staff member
Magus_Prime said:
Was able to log in but while it launched the relay browser, it failed to load the relay browser frames.
Click to expand...
My guess is that login didn't complete because of the crash we see at the end of the debug log, which crashed Mafia and dumped you back out into the pre-login screen. I've seen it before when launching the relay browser crashed.

The mall price database update code runs on logout only, not login (unless you have a custom login script, I suppose) so I don't think it would have been affected.

Your log shows
Code: 
class java.net.ConnectException: Connection timed out: connect
java.net.ConnectException: Connection timed out: connect
    at [...]
    at java.base/java.net.HttpURLConnection.getResponseCode(HttpURLConnection.java:529)
    at net.sourceforge.kolmafia.utilities.FileUtilities.getInputStreamFromConnection(FileUtilities.java:202)
    at net.sourceforge.kolmafia.utilities.FileUtilities.downloadFile(FileUtilities.java:288)
    at net.sourceforge.kolmafia.request.RelayRequest.sendLocalFile(RelayRequest.java:679)
    at net.sourceforge.kolmafia.request.RelayRequest.handleSimple(RelayRequest.java:3125)
    at net.sourceforge.kolmafia.request.RelayRequest.run(RelayRequest.java:3140)
    at net.sourceforge.kolmafia.RequestThread.postRequest(RequestThread.java:243)
    at net.sourceforge.kolmafia.RequestThread.postRequest(RequestThread.java:208)
    at net.sourceforge.kolmafia.webui.RelayAgent.readServerResponse(RelayAgent.java:455)
    at net.sourceforge.kolmafia.webui.RelayAgent.performRelay(RelayAgent.java:103)
    at net.sourceforge.kolmafia.webui.RelayAgent.run(RelayAgent.java:82)

so it appears the problem is in FileUtilities.downloadFile, and you have some network issue leading to a connection timeout.
 
M

Magus_Prime

Well-known member
I do not have the relay browser set to launch on login nor do I have a login script set. The only thing set to run on login is breakfast.
 
M

Magus_Prime

Well-known member
And this morning, with r26279, I was able to log in and everything, including the relay browser, loaded as expected. 🤷‍♂️
 
You must log in or register to reply here.
Top