Random E730053 errors

Hello,

I am using SCM Manager 2.42.2 on Debian Linux. It is only Subversion enabled in SCM Manager.

There is no problem at all about regular developer use case. All commits and updates from any developer works just fine. At least no problem reports that I am aware of.

Recently, I started checking build servers. I tested well known Jenkins in a VM on my own development machine. Test system was accessing SCM Manager over the internet. My development machine as metal is also accessing SCM Manager over the internet.

Once my Jenkins tests are complete, I spin up a new virtual server in the same physical server as SCM Manager working and installed Jenkins in it. Unfortunately, I started to got errors at checkout stage from Jenkins. Using Jenkins support forum, I am told it is believed to be a network problem of some kind.

Since there is no firewall on SCM Manager machine and only difference is accessing it over the internet and over LAN (actually VM reaching another VM on same server) and using command line subversion to do checkout seems to work, I did not know what else to do or check.

After some more trials with Jenkins, I could not solve the problem so switched testing GoCD which unlike Jenkins need subversion itself to be installed on the system.

It seemed to be working at first, but after a while I get random E730053 errors. They were not always happening as in Jenkins, but they do happen. Below is a log file of GoCD with the error from a job that I manually triggered today

##|08:26:52.784 [go] Job Started: 2023-03-19 08:26:52 TRT
##|08:26:52.784 
pr|08:26:52.784 [go] Start to prepare YazilimGuncelle/3/BuildStage/1/BuildJob on Build-Server [C:\Program Files (x86)\Go Agent]
##|08:26:52.862 [go] Cleaning working directory "C:\Program Files (x86)\Go Agent\pipelines\YazilimGuncelle" since stage is configured to clean working directory
pr|08:26:53.143 [go] Start to update materials.
pr|08:26:53.143 
pr|08:26:53.143 [go] Start updating utils at revision 63 from http://192.168.1.104:8080/scm/repo/scmadmin/utils/trunk
pe|08:26:53.534 STDERR: svn: E730053: Error running context: An established connection was aborted by the software in your host machine.  
&2|08:26:53.534 Failed to run svn --username scmadmin --password ****** checkout --non-interactive -r 63 http://192.168.1.104:8080/scm/repo/scmadmin/utils/trunk C:\Program Files (x86)\Go Agent\pipelines\YazilimGuncelle\utils
ex|08:26:53.534 [go] Job completed YazilimGuncelle/3/BuildStage/1/BuildJob on Build-Server [C:\Program Files (x86)\Go Agent]

I started to suspect this maybe a VM controller problem as none of the developers are using VM on same server as SCM Manager is working. But, I need to do more tests and research before concluding.

I am posting this with the hope that I might get some clue as to where else to check maybe using debug logs or similar.

Thanks & Regards,
Ertan

Hey Ertan, could you check your SCM-Manager logs if there is a reason for the connection abortion? You have no problems accessing this repository manually? Just with the tools?

Regards, Eduard

Hi Eduard,

Thank you for your message.

I could not find any problems with the logs. So far, I tried to produce DEBUG logs and still could not see anything particular that would cause a connection drop. This check I already did before my initial post.

Below is cropped part from logs where Jenkins got error. That log belongs to a different repository than my initial message. Problem is not related to a single repository as far as I can tell.

2023-03-14 21:15:03.429 [qtp2096171631-11] [          ] DEBUG sonia.scm.security.DAORealmHelper - try to authenticate scmadmin
2023-03-14 21:15:03.583 [qtp2096171631-11] [          ] DEBUG sonia.scm.security.ApiKeyTokenHandler - failed to read api token, perhaps it is a jwt token or a normal password
2023-03-14 21:15:03.584 [qtp2096171631-11] [          ] DEBUG sonia.scm.security.DAORealmHelper - try to authenticate scmadmin
2023-03-14 21:15:03.584 [qtp2096171631-11] [          ] DEBUG sonia.scm.legacy.LegacyRealm - hash contains non hex chars
2023-03-14 21:15:03.590 [qtp2096171631-11] [50TYVHzkX1] DEBUG sonia.scm.group.DefaultGroupCollector - collected following groups for principal scmadmin: [_authenticated]
2023-03-14 21:15:03.607 [qtp2096171631-11] [50TYVHzkX1] DEBUG sonia.scm.group.DefaultGroupCollector - collected following groups for principal scmadmin: [_authenticated]
2023-03-14 21:15:03.621 [qtp2096171631-11] [50TYVHzkX1] DEBUG sonia.scm.repository.api.RepositoryServiceFactory - create new repository service for repository gelisim_ortak_yazilimguncelle of type svn
2023-03-14 21:15:03.630 [qtp2096171631-11] [50TYVHzkX1] DEBUG sonia.scm.util.Decorators - decorate class sonia.scm.web.SvnDAVServlet with class sonia.scm.web.SvnPermissionFilterFactory
2023-03-14 21:15:03.638 [qtp2096171631-11] [50TYVHzkX1] DEBUG sonia.scm.util.Decorators - decorate class sonia.scm.web.SvnPermissionFilter with class sonia.scm.web.SvnGZipFilterFactory
2023-03-14 21:15:03.640 [qtp2096171631-11] [50TYVHzkX1] DEBUG sonia.scm.util.Decorators - decorate class sonia.scm.web.SvnDAVServlet with class sonia.scm.web.SvnPermissionFilterFactory
2023-03-14 21:15:03.640 [qtp2096171631-11] [50TYVHzkX1] DEBUG sonia.scm.util.Decorators - decorate class sonia.scm.web.SvnPermissionFilter with class sonia.scm.web.SvnGZipFilterFactory
2023-03-14 21:15:03.647 [qtp2096171631-11] [50TYVHzkX1] DEBUG sonia.scm.group.DefaultGroupCollector - collected following groups for principal scmadmin: [_authenticated]
2023-03-14 21:15:03.801 [qtp2096171631-14] [          ] DEBUG sonia.scm.security.DAORealmHelper - try to authenticate scmadmin
2023-03-14 21:15:03.891 [qtp2096171631-14] [          ] DEBUG sonia.scm.security.ApiKeyTokenHandler - failed to read api token, perhaps it is a jwt token or a normal password
2023-03-14 21:15:03.891 [qtp2096171631-14] [          ] DEBUG sonia.scm.security.DAORealmHelper - try to authenticate scmadmin
2023-03-14 21:15:03.891 [qtp2096171631-14] [          ] DEBUG sonia.scm.legacy.LegacyRealm - hash contains non hex chars
2023-03-14 21:15:03.897 [qtp2096171631-14] [F9TYVHzpT2] DEBUG sonia.scm.group.DefaultGroupCollector - collected following groups for principal scmadmin: [_authenticated]
2023-03-14 21:15:03.898 [qtp2096171631-14] [F9TYVHzpT2] DEBUG sonia.scm.group.DefaultGroupCollector - collected following groups for principal scmadmin: [_authenticated]
2023-03-14 21:15:03.899 [qtp2096171631-14] [F9TYVHzpT2] DEBUG sonia.scm.repository.api.RepositoryServiceFactory - create new repository service for repository ortak_yazilimguncelle of type svn
2023-03-14 21:15:03.899 [qtp2096171631-14] [F9TYVHzpT2] DEBUG sonia.scm.util.Decorators - decorate class sonia.scm.web.SvnDAVServlet with class sonia.scm.web.SvnPermissionFilterFactory
2023-03-14 21:15:03.899 [qtp2096171631-14] [F9TYVHzpT2] DEBUG sonia.scm.util.Decorators - decorate class sonia.scm.web.SvnPermissionFilter with class sonia.scm.web.SvnGZipFilterFactory
2023-03-14 21:15:03.900 [qtp2096171631-14] [F9TYVHzpT2] DEBUG sonia.scm.group.DefaultGroupCollector - collected following groups for principal scmadmin: [_authenticated]
2023-03-14 21:15:03.968 [qtp2096171631-14] [          ] DEBUG sonia.scm.security.DAORealmHelper - try to authenticate scmadmin
2023-03-14 21:15:03.983 [qtp2096171631-14] [          ] DEBUG sonia.scm.security.ApiKeyTokenHandler - failed to read api token, perhaps it is a jwt token or a normal password
2023-03-14 21:15:03.983 [qtp2096171631-14] [          ] DEBUG sonia.scm.security.DAORealmHelper - try to authenticate scmadmin
2023-03-14 21:15:03.983 [qtp2096171631-14] [          ] DEBUG sonia.scm.legacy.LegacyRealm - hash contains non hex chars
2023-03-14 21:15:03.992 [qtp2096171631-14] [CgTYVHzqy3] DEBUG sonia.scm.group.DefaultGroupCollector - collected following groups for principal scmadmin: [_authenticated]
2023-03-14 21:15:03.994 [qtp2096171631-14] [CgTYVHzqy3] DEBUG sonia.scm.group.DefaultGroupCollector - collected following groups for principal scmadmin: [_authenticated]
2023-03-14 21:15:03.994 [qtp2096171631-14] [CgTYVHzqy3] DEBUG sonia.scm.repository.api.RepositoryServiceFactory - create new repository service for repository ortak_yazilimguncelle of type svn
2023-03-14 21:15:03.995 [qtp2096171631-14] [CgTYVHzqy3] DEBUG sonia.scm.util.Decorators - decorate class sonia.scm.web.SvnDAVServlet with class sonia.scm.web.SvnPermissionFilterFactory
2023-03-14 21:15:03.995 [qtp2096171631-14] [CgTYVHzqy3] DEBUG sonia.scm.util.Decorators - decorate class sonia.scm.web.SvnPermissionFilter with class sonia.scm.web.SvnGZipFilterFactory
2023-03-14 21:15:03.995 [qtp2096171631-14] [CgTYVHzqy3] DEBUG sonia.scm.group.DefaultGroupCollector - collected following groups for principal scmadmin: [_authenticated]
2023-03-14 21:15:04.016 [qtp2096171631-13] [          ] DEBUG sonia.scm.security.DAORealmHelper - try to authenticate scmadmin
2023-03-14 21:15:04.040 [qtp2096171631-13] [          ] DEBUG sonia.scm.security.ApiKeyTokenHandler - failed to read api token, perhaps it is a jwt token or a normal password
2023-03-14 21:15:04.040 [qtp2096171631-13] [          ] DEBUG sonia.scm.security.DAORealmHelper - try to authenticate scmadmin
2023-03-14 21:15:04.040 [qtp2096171631-13] [          ] DEBUG sonia.scm.legacy.LegacyRealm - hash contains non hex chars
2023-03-14 21:15:04.050 [qtp2096171631-13] [9WTYVHzs14] DEBUG sonia.scm.group.DefaultGroupCollector - collected following groups for principal scmadmin: [_authenticated]
2023-03-14 21:15:04.061 [qtp2096171631-13] [9WTYVHzs14] DEBUG sonia.scm.group.DefaultGroupCollector - collected following groups for principal scmadmin: [_authenticated]
2023-03-14 21:15:04.062 [qtp2096171631-13] [9WTYVHzs14] DEBUG sonia.scm.repository.api.RepositoryServiceFactory - create new repository service for repository ortak_yazilimguncelle of type svn
2023-03-14 21:15:04.063 [qtp2096171631-13] [9WTYVHzs14] DEBUG sonia.scm.util.Decorators - decorate class sonia.scm.web.SvnDAVServlet with class sonia.scm.web.SvnPermissionFilterFactory
2023-03-14 21:15:04.063 [qtp2096171631-13] [9WTYVHzs14] DEBUG sonia.scm.util.Decorators - decorate class sonia.scm.web.SvnPermissionFilter with class sonia.scm.web.SvnGZipFilterFactory
2023-03-14 21:15:04.063 [qtp2096171631-13] [9WTYVHzs14] DEBUG sonia.scm.group.DefaultGroupCollector - collected following groups for principal scmadmin: [_authenticated]

Jenkins receive error after below lines in above log. These are just example, log has more such lines. Probably it is Jenkins making several trials before actual error reporting.
2023-03-14 21:15:03.647 [qtp2096171631-11]
2023-03-14 21:15:03.900 [qtp2096171631-14]

There is no problem reaching any repository using browser. Again, we do not do that at all. When browser is used it is mostly for adding a new repository or just for checking out some initial commit dates for certain repositories. It is always TortoiseSVN what is used as repository commit/update etc. There is no problem with the TortoiseSVN on developer machines. Not before Jenkins, not after Jenkins.

Today, I will try to grab a different hardware (not a VM) on the same LAN as the SCM Manager and do some more tests to see if the VM controller is the culprit or not.

Regards,
Ertan

I confirm that there is no problem reaching SCM Manager over physical computer on the same subnet LAN. The communication between two VM servers seems to be the problem.

I have no solution so far as there is no such problem reported before and using different NIC types under VM settings does not help.

Jenkins always gets error.
GoCD uses subversion command line and it occasionally gets error.

There is no specific log records in SCM Manager when the error occurs. Build server (Jenkins or GoCD) logs have “host dropped connection” like messages.

I just wanted to record this here as someone else might have the same problem.