maziac/DeZog

Socket time out on real next

Closed this issue · 30 comments

infromthecold commented

I am getting a socket timeout on a real next using the serial cable plugged into port 2, It only happens on the latest update.

Version: 1.78.2 (system setup)
Commit: b3e4e68a0bc097f0ae7907b217c1119af9e03435
Date: 2023-05-10T14:39:26.248Z
Electron: 22.5.2
Chromium: 108.0.5359.215
Node.js: 16.17.1
V8: 10.8.168.25-electron.0
OS: Windows_NT x64 10.0.19045
Sandboxed: Yes

DeZog v3.3.0 (with the latest update for the enNextMf.rom)

So everything is the latest version

here is the output at a breakpoint

<<< Remote: Received Response:
Length: 3 (3 0 0 0)
SeqNo: 32
Data: 0 0

ZxNextSerialRemote: Sending Command CMD_SET_SLOT
Length: 2 (2 0 0 0)
SeqNo: 33
Cmd: 10
Data: 0 255

<<< Remote: Received Response:
Length: 2 (2 0 0 0)
SeqNo: 33
Data: 0

ZxNextSerialRemote: Sending Command CMD_SET_SLOT
Length: 2 (2 0 0 0)
SeqNo: 34
Cmd: 10
Data: 1 255

<<< Remote: Received Response:
Length: 2 (2 0 0 0)
SeqNo: 34
Data: 0

ZxNextSerialRemote: Sending Command CMD_SET_SLOT
Length: 2 (2 0 0 0)
SeqNo: 35
Cmd: 10
Data: 2 10

<<< Remote: Received Response:
Length: 2 (2 0 0 0)
SeqNo: 35
Data: 0

ZxNextSerialRemote: Sending Command CMD_SET_SLOT
Length: 2 (2 0 0 0)
SeqNo: 36
Cmd: 10
Data: 3 11

<<< Remote: Received Response:
Length: 2 (2 0 0 0)
SeqNo: 36
Data: 0

ZxNextSerialRemote: Sending Command CMD_SET_SLOT
Length: 2 (2 0 0 0)
SeqNo: 37
Cmd: 10
Data: 4 4

<<< Remote: Received Response:
Length: 2 (2 0 0 0)
SeqNo: 37
Data: 0

ZxNextSerialRemote: Sending Command CMD_SET_SLOT
Length: 2 (2 0 0 0)
SeqNo: 38
Cmd: 10
Data: 5 5

<<< Remote: Received Response:
Length: 2 (2 0 0 0)
SeqNo: 38
Data: 0

ZxNextSerialRemote: Sending Command CMD_SET_SLOT
Length: 2 (2 0 0 0)
SeqNo: 39
Cmd: 10
Data: 6 0

<<< Remote: Received Response:
Length: 2 (2 0 0 0)
SeqNo: 39
Data: 0

ZxNextSerialRemote: Sending Command CMD_SET_SLOT
Length: 2 (2 0 0 0)
SeqNo: 40
Cmd: 10
Data: 7 1

<<< Remote: Received Response:
Length: 2 (2 0 0 0)
SeqNo: 40
Data: 0

ZxNextSerialRemote: Sending Command CMD_SET_REGISTER
Length: 3 (3 0 0 0)
SeqNo: 41
Cmd: 4
Data: 1 0 96

<<< Remote: Received Response:
Length: 1 (1 0 0 0)
SeqNo: 41
Data: ---

ZxNextSerialRemote: Sending Command CMD_SET_REGISTER
Length: 3 (3 0 0 0)
SeqNo: 42
Cmd: 4
Data: 0 0 192

<<< Remote: Received Response:
Length: 1 (1 0 0 0)
SeqNo: 42
Data: ---

ZxNextSerialRemote: Sending Command CMD_GET_REGISTERS
Length: 0 (0 0 0 0)
SeqNo: 43
Cmd: 3
Data: ---

<<< Remote: Received Response:
Length: 38 (38 0 0 0)
SeqNo: 43
Data: 0 192 0 96 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 8 255 255 10 11 4 5 0 1

ZxNextSerialRemote: Sending Command CMD_SET_BREAKPOINTS
Length: 3 (3 0 0 0)
SeqNo: 44
Cmd: 13
Data: 251 177 6

<<< Remote: Received Response:
Length: 2 (2 0 0 0)
SeqNo: 44
Data: 50

ZxNextSerialRemote: Sending Command CMD_CONTINUE
Length: 11 (11 0 0 0)
SeqNo: 45
Cmd: 6
Data: 0 0 0 0 0 0 0 0 0 0 0

<<< Remote: Received Response:
Length: 1 (1 0 0 0)
SeqNo: 45
Data: 128 128 128 128 128 128 128 128 128 128 128 128 128 128 128 128 128 128 128 128 128 128 128 128

...
Pause for 23.069 secs.
...
<<< Remote: Received Notification:
Length: 7 (7 0 0 0)
SeqNo: 0
Data: 1 2 251 177 6 0

ZxNextSerialRemote: Sending Command CMD_RESTORE_MEM
Length: 4 (4 0 0 0)
SeqNo: 46
Cmd: 14
Data: 251 177 6 50

<<< Remote: Received Response:
Length: 1 (1 0 0 0)
SeqNo: 46
Data: ---

ZxNextSerialRemote: Sending Command CMD_GET_REGISTERS
Length: 0 (0 0 0 0)
SeqNo: 47
Cmd: 3
Data: ---

<<< Remote: Received Response:
Length: 38 (38 0 0 0)
SeqNo: 47
Data: 251 177 252 95 66 100 11 0 0 96 7 138 44 192 171 138 0 0 0 0 0 0 0 0 16 82 255 0 8 255 255 10 11 4 5 18 19

ZxNextSerialRemote: Sending Command CMD_GET_REGISTERS
Length: 0 (0 0 0 0)
SeqNo: 48
Cmd: 3
Data: ---

<<< Remote: Received Response:
Length: 38 (38 0 0 0)
SeqNo: 48
Data: 251 177 252 95 66 100 11 0 0 96 7 138 44 192 171 138 0 0 0 0 0 0 0 0 16 82 255 0 8 255 255 10 11 4 5 18 19

ZxNextSerialRemote: Sending Command CMD_READ_MEM
Length: 5 (5 0 0 0)
SeqNo: 49
Cmd: 8
Data: 0 252 95 4 0

<<< Remote: Received Response:
Length: 5 (5 0 0 0)
SeqNo: 49
Data: 66 4 125 176

ZxNextSerialRemote: Sending Command CMD_READ_MEM
Length: 5 (5 0 0 0)
SeqNo: 50
Cmd: 8
Data: 0 122 176 3 0

<<< Remote: Received Response:
Length: 4 (4 0 0 0)
SeqNo: 50
Data: 205 248 177

ZxNextSerialRemote: Sending Command CMD_READ_MEM
Length: 5 (5 0 0 0)
SeqNo: 51
Cmd: 8
Data: 0 63 4 3 0

<<< Remote: Received Response:
Length: 4 (4 0 0 0)
SeqNo: 51
Data: 192 2 49

ZxNextSerialRemote: Sending Command CMD_READ_MEM
Length: 5 (5 0 0 0)
SeqNo: 52
Cmd: 8
Data: 0 0 0 0 128

Warning: No response received from remote.

ZxNextSerialRemote: Sending Command CMD_READ_MEM
Length: 5 (5 0 0 0)
SeqNo: 53
Cmd: 8
Data: 0 181 138 2 0

<<< Remote: Received Response:
Length: 32769 (1 128 0 0)
SeqNo: 52
Data: 24 100 251 237 146 87 241 201 42 93 92 34 95 92 24 67 195 242 21 255 255 255 255 255 195 85 21 126 205 125 0 208 195 91 21 24 247 255 255 255 195 91 51 255 255 255 255 255 197 42 97 92 229 195 158 22 245 229 42 120 92 35 34 120 92 124 181 32 3 253 52 64 197 213 205 110 56 209 193 225 241 251 201 225 110 253 117 0 237 123 61 92 195 197 22 255 255 255 255 255 255 255 245 237 87 245 237 87 243 197 14 255 237 145 80 94 42 93 92 35 34 93 92 126 201 254 33 208 254 13 200 254 16 216 254 24 63 216 35 254 22 56 1 35 55 34 93 92 201 191 82 78 196 73 78 75 69 89 164 80 201 70 206 80 79 73 78 212 83 67 82 69 69 78 164 65 84 84 210 65 212 84 65 194 86 65 76 164 67 79 68 197 86 65 204 76 69 206 83 73 206 67 79 211 84 65 206 65 83 206 65 67 211 65 84 206 76 206 69 88 208 73 78 212 83 81 210 83 71 206 65 66 211 80 69 69 203 73 206 85 83 210 83 84 82 164 67 72 82 164 78 79 212 66 73 206 79 210 65 78 196 60 189 62 189 60 190 76 73 78 197 84 72 69 206 84 207 83 84 69 208 68 69 70 32 70 206 67 65 212 70 79 82 77 65 212 77 79 86 197 ...

Error: Error: DZRP: Received wrong SeqNo. '52' instead of expected '53'

maziac commented

Hi,

did you updated just now. I.e. was this (new) version working before?

Can you please share your launch.json?

It is having problems at the reading of memory.
Do you have special memory views open?

infromthecold commented

Yes, this is the latest version DeZog v3.3.0

Version: 1.78.2 (system setup)
Commit: b3e4e68a0bc097f0ae7907b217c1119af9e03435
Date: 2023-05-10T14:39:26.248Z
Electron: 22.5.2
Chromium: 108.0.5359.215
Node.js: 16.17.1
V8: 10.8.168.25-electron.0
OS: Windows_NT x64 10.0.19045
Sandboxed: Yes

infromthecold commented

Its the same on my laptop too, is there a way of adjusting the time out?

maziac commented

Can you please share your launch.json?

Do you have any memory views open? If so, please try without.

infromthecold commented

{
// Use IntelliSense to learn about possible attributes. //cspect
// Hover to view descriptions of existing attributes.
// For more information, visit: https://go.microsoft.com/fwlink/?linkid=830387
"version": "0.2.0",
"configurations":
[

  //--------------------------------------------------------------------------
  //
  // on the the real spectrum next with the register window
  //
  //--------------------------------------------------------------------------
        {    
	"type": "dezog",
	"request": "launch",
	"name": "On Next with registers",               
	"remoteType": "zxnext",	
	"zxnext": 
	{			
		"baudrate": 921600, 
		//"port": 12000,
		"serial": "COM8"
	},
	"sjasmplus": 
	[
		{				
			"useFiles": true,				
			"asm": "sjasmplus", 	
			"path": "${workspaceFolder}\\main.sld.txt", //list",
			"mainFile": "${relativeFileDirname}/main.asm",	
			"cwd": "${workspaceFolder}",
		}
	],
	"disassemblerArgs": 
	{
		"esxdosRst": true,
		"numberOfLines": 40,
	},
	"load": "F:\\Projects\\Komodo\\Build\\main.nex",
	//"skipInterrupt": false,
	"startAutomatically": true,	
	"history": 
	{
		"reverseDebugInstructionCount": 10000,
		"codeCoverageEnabled": true
	},
	"commandsAfterLaunch":
	[
		"-rmv",
	//	"-LOGPOINT enable",
	],		
	"rootFolder": "${fileDirname}",
	"topOfStack": "StackStart",
	"smallValuesMaximum": 513,
        	"tmpDir": ".tmp"
  },

  //--------------------------------------------------------------------------
  //
  // on the the real spectrum next
  //
  //--------------------------------------------------------------------------

  {    
	"type": "dezog",
	"request": "launch",
	"name": "On Next",               
	"remoteType": "zxnext",	
	"zxnext": 
	{			
		"baudrate": 921600, 
		//"port": 12000,
		"serial": "COM8"
	},
	"sjasmplus": 
	[
		{				
			"useFiles": true,		  
			"asm": "sjasmplus", 	
			"path": "${workspaceFolder}\\main.sld.txt", //list",
			"mainFile": "${relativeFileDirname}/main.asm",	
			"cwd": "${workspaceFolder}",
		}
	],
	"disassemblerArgs": 
	{
		"esxdosRst": true,
		"numberOfLines": 40,
	},
	"load": "F:\\Projects\\Komodo\\Build\\main.nex",
	//"skipInterrupt": false,
	"startAutomatically": true,	
	"history": 
	{
		"reverseDebugInstructionCount": 10000,
		"codeCoverageEnabled": true
	},
//	"commandsAfterLaunch":
//	[
//		"-LOGPOINT enable",
//	],		
	"rootFolder": "${fileDirname}",
	"topOfStack": "StackStart",
	"smallValuesMaximum": 513,
        	"tmpDir": ".tmp"
  },

  //--------------------------------------------------------------------------
  //
  // on the c spect emulator
  //
  //--------------------------------------------------------------------------

  {    
	"type": "dezog",
	"request": "launch",
	"name": "On CSpect",               
	"remoteType": "cspect",	
	"zxnext": 
	{			
		"hostname": "localhost",
		"port": 11000
	},
	"sjasmplus": 
	[
		{				
			"useFiles": true,		  
			"asm": "sjasmplus", 	
			"path": "${workspaceFolder}\\main.sld.txt", //list",
			"mainFile": "${relativeFileDirname}/main.asm",	
			"cwd": "${workspaceFolder}"	//,
		}
	],
	"disassemblerArgs": 
	{
		"esxdosRst": true,
		"numberOfLines": 40,
	},
	"load": "F:\\Projects\\Komodo\\Build\\main.nex",
	//"skipInterrupt": false,
	"startAutomatically": true,	
	"history": 
	{
		"reverseDebugInstructionCount": 10000,
		//"codeCoverageEnabled": true
	},
	"commandsAfterLaunch":
	[
	//	"-LOGPOINT enable",
	],		
	"rootFolder": "${fileDirname}",
	"topOfStack": "StackStart",
	"smallValuesMaximum": 513,
        	"tmpDir": ".tmp"
  }	
    ]
}
maziac commented

Does this happen also right after starting?
Does it happen when you step or only at a breakpoint? Does it happen for all breakpoints or only a specific one?

I can see from the log that DeZog tries to read 32kB of memory.
Do you have such a large memory view open? Try closing it.

infromthecold commented
infromthecold commented
maziac commented

I see 2 memory reads of 32k each.
One at address 0, the other at 8000h.
Die you have any idea where those come from?
Do you have large arrays in the WATCH area?

maziac commented

At the moment the timeout is not adjustable by the user.
So, for testing purposes, I attached here a version which increases the timeout from 1s to 10s.
dezog-3.3.0-timeout10.vsix.zip
Please give it a try.

infromthecold commented
infromthecold commented
infromthecold commented
maziac commented

Could you do me a favor and try with this version:
dezog-3.3.0-timeoutsetting.vsix.zip
It has a setting to adjust the timeout, i.e.:

            "zxnext": {
                "serial": "COM8",
                "timeout": 2
            },

The timeout value is in seconds. The value was 1 s in the past.
Could you try with different values: 2, 3, 4, 5, 8, 10.
To see when it becomes stable for you.

Then I could adjust the default value to something more meaningful.

infromthecold commented
maziac commented

Any new findings?

maziac commented

I have here a new version. In the previous version there is still an old timeout value used for the chunk timeout.
I changed it so that this timeout also uses the value from the launch.json.
dezog-3.3.1-rc2.vsix.zip

infromthecold commented
infromthecold commented
maziac commented

Which timeout value have you been using?

infromthecold commented
maziac commented

Fixed in 3.3.1 (default timeout = 5s).

infromthecold commented
infromthecold commented
maziac commented

But it was working for some time and now it suddenly happened?

infromthecold commented
infromthecold commented
infromthecold commented
maziac commented

So, did you find any setup that is causing this issue?

infromthecold commented