wwivbbs/wwiv

Duplicate netmail from remote systems

Opened this issue · 18 comments

WIndows 10, w32 Build 5.8.0.3665

Initially thought it was just from Jahmas, but after receiving 44 duplicate e-mails from him, I sent myself mail from his BBS. 5 dupes received so far.

Netmail with Xenos, three dupes from him so far.

Something in the last month or so in updates?

wwiv commented

Anywhere else other than him? He's on a very old WWIV:

WWIV Bulletin Board System v5.00  (Build 1035)
Copyright (C) 1998-2014, WWIV Software Services.
All Rights Reserved.

Licensed under the Apache License.
Please see http://wwiv.sourceforge.net for more information

Compile Time  : Oct  2 2014, 22:26:58
SysOp Name:   : Jahmas   

Look to see if for some reason your bbs isn't deleting the packets from him (look in the wwivnet directory)

No packets that I would recognize, but I do have an UNWANTED.NET file that I've never seen before.

Ã� ? � � Ì–Öc�� NETTEST test Aladdin #1 @63
Sun Jan 29 23:54:52 2023
�0R 53 - 01/29/23 09:03:23 WWIVnet ->707
�0R 38RC6 - 01/29/23 11:50:20 WWIVnet ->1
�0R 53 - 01/29/23 23:55:26 WWIVnet ->60
�0R 53 - 01/29/23 23:54:53 WWIVnet ->63
RE: test

�0PID: WWIV 5.8.0.development
test

�Ã� ? � � Ì–Öc�� NETTEST test Aladdin #1 @63
Sun Jan 29 23:54:52 2023
�0R 53 - 01/29/23 09:19:24 WWIVnet ->707
�0R 38RC6 - 01/29/23 12:15:20 WWIVnet ->1
�0R 53 - 01/29/23 23:55:26 WWIVnet ->60
�0R 53 - 01/29/23 23:54:53 WWIVnet ->63
RE: test

�0PID: WWIV 5.8.0.development
test

�Ã� ? � � Ì–Öc�� NETTEST test Aladdin #1 @63
Sun Jan 29 23:54:52 2023
�0R 53 - 01/29/23 10:07:22 WWIVnet ->707
�0R 38RC6 - 01/29/23 12:55:20 WWIVnet ->1
�0R 53 - 01/29/23 23:55:26 WWIVnet ->60
�0R 53 - 01/29/23 23:54:53 WWIVnet ->63
RE: test

�0PID: WWIV 5.8.0.development
test

�Ã� ? � � Ì–Öc�� NETTEST test Aladdin #1 @63
Sun Jan 29 23:54:52 2023
�0R 53 - 01/29/23 10:39:25 WWIVnet ->707
�0R 38RC6 - 01/29/23 13:25:20 WWIVnet ->1
�0R 53 - 01/29/23 23:55:26 WWIVnet ->60
�0R 53 - 01/29/23 23:54:53 WWIVnet ->63
RE: test

�0PID: WWIV 5.8.0.development
test

�Ã� ? � � Ì–Öc�� NETTEST test Aladdin #1 @63
Sun Jan 29 23:54:52 2023
�0R 53 - 01/29/23 10:55:27 WWIVnet ->707
�0R 38RC6 - 01/29/23 13:40:20 WWIVnet ->1
�0R 53 - 01/29/23 23:55:26 WWIVnet ->60
�0R 53 - 01/29/23 23:54:53 WWIVnet ->63
RE: test

�0PID: WWIV 5.8.0.development
test

�Ã� ? � � Ì–Öc�� NETTEST test Aladdin #1 @63
Sun Jan 29 23:54:52 2023
�0R 53 - 01/29/23 12:29:34 WWIVnet ->707
�0R 38RC6 - 01/29/23 15:23:07 WWIVnet ->1
�0R 53 - 01/29/23 23:55:26 WWIVnet ->60
�0R 53 - 01/29/23 23:54:53 WWIVnet ->63
RE: test

�0PID: WWIV 5.8.0.development
test

�Ã� ? � � Ì–Öc�� NETTEST test Aladdin #1 @63
Sun Jan 29 23:54:52 2023
�0R 53 - 01/29/23 13:01:35 WWIVnet ->707
�0R 38RC6 - 01/29/23 15:36:27 WWIVnet ->1
�0R 53 - 01/29/23 23:55:26 WWIVnet ->60
�0R 53 - 01/29/23 23:54:53 WWIVnet ->63
RE: test

�0PID: WWIV 5.8.0.development
test

�Ã� ? � � Ì–Öc�� NETTEST test Aladdin #1 @63
Sun Jan 29 23:54:52 2023
�0R 53 - 01/29/23 15:23:41 WWIVnet ->707
�0R 38RC6 - 01/29/23 18:20:19 WWIVnet ->1
�0R 53 - 01/29/23 23:55:26 WWIVnet ->60
�0R 53 - 01/29/23 23:54:53 WWIVnet ->63
RE: test

�0PID: WWIV 5.8.0.development
test

�Ã� ? � � Ì–Öc�� NETTEST test Aladdin #1 @63
Sun Jan 29 23:54:52 2023
�0R 53 - 01/29/23 17:44:48 WWIVnet ->707
�0R 38RC6 - 01/29/23 20:35:19 WWIVnet ->1
�0R 53 - 01/29/23 23:55:26 WWIVnet ->60
�0R 53 - 01/29/23 23:54:53 WWIVnet ->63
RE: test

�0PID: WWIV 5.8.0.development
test

�Ã� ? � � Ì–Öc�� NETTEST test Aladdin #1 @63
Sun Jan 29 23:54:52 2023
�0R 53 - 01/29/23 19:33:53 WWIVnet ->707
�0R 38RC6 - 01/29/23 22:25:19 WWIVnet ->1
�0R 53 - 01/29/23 23:55:26 WWIVnet ->60
�0R 53 - 01/29/23 23:54:53 WWIVnet ->63
RE: test

�0PID: WWIV 5.8.0.development
test

�Ã� ? � � Ì–Öc�� NETTEST test Aladdin #1 @63
Sun Jan 29 23:54:52 2023
�0R 53 - 01/30/23 00:04:02 WWIVnet ->707
�0R 38RC6 - 01/30/23 03:00:24 WWIVnet ->1
�0R 53 - 01/29/23 23:55:26 WWIVnet ->60
�0R 53 - 01/29/23 23:54:53 WWIVnet ->63
RE: test

�0PID: WWIV 5.8.0.development
test

Three more dupes in from @255. These are from a single e-mail sent from there.
No further dupes from Xenos.

I have a snip from network1.log:
The files noted are deleted as they should be. Nothing hanging around.

--
2023-02-01 19:16:13,272 VER-2 þ 19:16:13 - net53 network1 [5.8.0.3665] (Jan 28 2023, 14:58:55) [WWIVnet]
2023-02-01 19:16:13,282 VER-2 Total : 5 msgs, 2k
2023-02-01 19:16:13,286 VER-2 @1 : 5 msgs, 2k
2023-02-01 19:16:13,291 VER-3 Saving contact.net to: C:\WWIV\NETWORKS\WWIVNET\contact.net
2023-02-01 19:16:13,300 VER-3 File::Open '"C:\WWIV\NETWORKS\WWIVNET\contact.net"', access=33538, handle=5
2023-02-01 19:16:13,311 VER-2 þ 19:16:13 - net53 network1 [5.8.0.3665] (Jan 28 2023, 14:58:55) [WWIVnet]
2023-02-01 19:16:13,320 VER-2 - Total : 5 msgs, 2k
2023-02-01 19:16:13,325 VER-2 - @1 : 5 msgs, 2k
2023-02-01 19:16:13,330 VER-1 ~SemaphoreFile(): "C:\WWIV\NETWORKS\WWIVNET\network1.bsy"; fd: 3
2023-02-01 19:16:13,340 START network1 exiting at Wed Feb 1 19:16:13 2023
2023-02-01 19:23:53,365 VER-3 Ignoring dot argument since no mapping is defined by the application.
2023-02-01 19:23:53,375 VER-3 Ignoring dot argument since no mapping is defined by the application.
2023-02-01 19:23:53,385 VER-3 ReadFileIntoString:
2023-02-01 19:23:53,390 VER-3 ReadFileIntoString:
2023-02-01 19:23:53,398 VER-3 ReadFileIntoString:
2023-02-01 19:23:53,403 VER-3 ReadFileIntoString:
2023-02-01 19:23:53,408 START network1.exe [5.8.0.3665] for network: wwivnet
2023-02-01 19:23:53,409 VER-3 Reading bbsdata.net..
2023-02-01 19:23:53,414 VER-3 File::Open '"C:\WWIV\NETWORKS\WWIVNET\bbsdata.net"', access=32770, handle=3
2023-02-01 19:23:53,425 VER-2 SemaphoreFile::try_acquire: '"C:\WWIV\NETWORKS\WWIVNET\network1.bsy"'
2023-02-01 19:23:53,436 INFO * Analyzing WWIVnet pending files...
2023-02-01 19:23:53,442 INFO Processing: "C:\WWIV\NETWORKS\WWIVNET\"p1-c-0.net
2023-02-01 19:23:53,450 VER-3 File::Open '"C:\WWIV\NETWORKS\WWIVNET\p1-c-0.net"', access=32768, handle=5
2023-02-01 19:23:53,460 VER-2 get_forsys (forward to systen number) for node: 1
2023-02-01 19:23:53,468 VER-2 get_forsys: route to node: 1; is through node: 1
2023-02-01 19:23:53,475 VER-2 get_forsys (forward to systen number) for node: 54
2023-02-01 19:23:53,483 VER-2 get_forsys: route to node: 54; is through node: 1
2023-02-01 19:23:53,490 VER-2 get_forsys (forward to systen number) for node: 60
2023-02-01 19:23:53,497 VER-2 get_forsys: route to node: 60; is through node: 1
2023-02-01 19:23:53,505 VER-2 get_forsys (forward to systen number) for node: 61
2023-02-01 19:23:53,513 VER-2 get_forsys: route to node: 61; is through node: 1
2023-02-01 19:23:53,520 VER-2 get_forsys (forward to systen number) for node: 63
2023-02-01 19:23:53,528 VER-2 get_forsys: route to node: 63; is through node: 1
2023-02-01 19:23:53,535 VER-2 get_forsys (forward to systen number) for node: 90
2023-02-01 19:23:53,542 VER-2 get_forsys: route to node: 90; is through node: 1
2023-02-01 19:23:53,550 VER-2 get_forsys (forward to systen number) for node: 101
2023-02-01 19:23:53,557 VER-2 get_forsys: route to node: 101; is through node: 1
2023-02-01 19:23:53,564 VER-2 get_forsys (forward to systen number) for node: 102
2023-02-01 19:23:53,572 VER-2 get_forsys: route to node: 102; is through node: 1
2023-02-01 19:23:53,579 VER-2 get_forsys (forward to systen number) for node: 104
2023-02-01 19:23:53,587 VER-2 get_forsys: route to node: 104; is through node: 1
2023-02-01 19:23:53,594 VER-2 get_forsys (forward to systen number) for node: 105
2023-02-01 19:23:53,602 VER-2 get_forsys: route to node: 105; is through node: 1
2023-02-01 19:23:53,610 VER-2 get_forsys (forward to systen number) for node: 108
2023-02-01 19:23:53,617 VER-2 get_forsys: route to node: 108; is through node: 1
2023-02-01 19:23:53,625 VER-2 get_forsys (forward to systen number) for node: 111
2023-02-01 19:23:53,633 VER-2 get_forsys: route to node: 111; is through node: 1
2023-02-01 19:23:53,640 VER-2 get_forsys (forward to systen number) for node: 114
2023-02-01 19:23:53,648 VER-2 get_forsys: route to node: 114; is through node: 1
2023-02-01 19:23:53,655 VER-2 get_forsys (forward to systen number) for node: 116
2023-02-01 19:23:53,663 VER-2 get_forsys: route to node: 116; is through node: 1
2023-02-01 19:23:53,676 VER-2 get_forsys (forward to systen number) for node: 117
2023-02-01 19:23:53,686 VER-2 get_forsys: route to node: 117; is through node: 1
2023-02-01 19:23:53,693 VER-2 get_forsys (forward to systen number) for node: 119
2023-02-01 19:23:53,705 VER-2 get_forsys: route to node: 119; is through node: 1
2023-02-01 19:23:53,711 VER-2 get_forsys (forward to systen number) for node: 125
2023-02-01 19:23:53,719 VER-2 get_forsys: route to node: 125; is through node: 1
2023-02-01 19:23:53,727 VER-2 get_forsys (forward to systen number) for node: 126
2023-02-01 19:23:53,734 VER-2 get_forsys: route to node: 126; is through node: 1
2023-02-01 19:23:53,742 VER-2 get_forsys (forward to systen number) for node: 127
2023-02-01 19:23:53,750 VER-2 get_forsys: route to node: 127; is through node: 1
2023-02-01 19:23:53,757 VER-2 get_forsys (forward to systen number) for node: 129
2023-02-01 19:23:53,765 VER-2 get_forsys: route to node: 129; is through node: 1
2023-02-01 19:23:53,772 VER-2 get_forsys (forward to systen number) for node: 130
2023-02-01 19:23:53,780 VER-2 get_forsys: route to node: 130; is through node: 1
2023-02-01 19:23:53,787 VER-2 get_forsys (forward to systen number) for node: 132
2023-02-01 19:23:53,796 VER-2 get_forsys: route to node: 132; is through node: 1
2023-02-01 19:23:53,802 VER-2 get_forsys (forward to systen number) for node: 180
2023-02-01 19:23:53,810 VER-2 get_forsys: route to node: 180; is through node: 1
2023-02-01 19:23:53,817 VER-2 get_forsys (forward to systen number) for node: 206
2023-02-01 19:23:53,824 VER-2 get_forsys: route to node: 206; is through node: 1
2023-02-01 19:23:53,832 VER-2 get_forsys (forward to systen number) for node: 255
2023-02-01 19:23:53,839 VER-2 get_forsys: route to node: 255; is through node: 1
2023-02-01 19:23:53,846 VER-2 get_forsys (forward to systen number) for node: 513
2023-02-01 19:23:53,854 VER-2 get_forsys: route to node: 513; is through node: 1
2023-02-01 19:23:53,862 VER-2 get_forsys (forward to systen number) for node: 514
2023-02-01 19:23:53,869 VER-2 get_forsys: route to node: 514; is through node: 1
2023-02-01 19:23:53,877 VER-2 get_forsys (forward to systen number) for node: 8315
2023-02-01 19:23:53,884 VER-2 get_forsys: route to node: 8315; is through node: 1
2023-02-01 19:23:53,891 VER-2 write_wwivnet_packet: C:\WWIV\NETWORKS\WWIVNET\s1.net
2023-02-01 19:23:53,899 INFO write_wwivnet_packet: Writing type 26/0 message to NetPacket: C:\WWIV\NETWORKS\WWIVNET\s1.net
2023-02-01 19:23:53,910 VER-3 File::Open '"C:\WWIV\NETWORKS\WWIVNET\s1.net"', access=33026, handle=6
2023-02-01 19:23:53,921 INFO Deleting: "C:\WWIV\NETWORKS\WWIVNET\"p1-c-0.net
2023-02-01 19:23:53,929 INFO * Updating WWIVnet contact.net...
2023-02-01 19:23:53,935 VER-3 File::Open '"C:\WWIV\NETWORKS\WWIVNET\contact.net"', access=32768, handle=5
2023-02-01 19:23:53,946 VER-1 Updating contact entry for node: @1
2023-02-01 19:23:53,952 VER-1 Updating contact entry for node: @32767
2023-02-01 19:23:53,959 INFO Stats:
k: 1: files: 1; bytes: 327

2023-02-01 19:23:53,965 VER-2 þ 19:23:53 - net53 network1 [5.8.0.3665] (Jan 28 2023, 14:58:55) [WWIVnet]
2023-02-01 19:23:53,975 VER-2 Total : 1 msgs, 1k
2023-02-01 19:23:53,980 VER-2 @1 : 1 msgs, 1k
2023-02-01 19:23:53,985 VER-3 Saving contact.net to: C:\WWIV\NETWORKS\WWIVNET\contact.net
2023-02-01 19:23:53,994 VER-3 File::Open '"C:\WWIV\NETWORKS\WWIVNET\contact.net"', access=33538, handle=5
2023-02-01 19:23:54,005 VER-2 þ 19:23:54 - net53 network1 [5.8.0.3665] (Jan 28 2023, 14:58:55) [WWIVnet]
2023-02-01 19:23:54,015 VER-2 - Total : 1 msgs, 1k
2023-02-01 19:23:54,019 VER-2 - @1 : 1 msgs, 1k
2023-02-01 19:23:54,024 VER-1 ~SemaphoreFile(): "C:\WWIV\NETWORKS\WWIVNET\network1.bsy"; fd: 3
2023-02-01 19:23:54,034 START network1 exiting at Wed Feb 1 19:23:54 2023

network2log.zip

Hoping this will help. It does look like I keep receiving the packets.

wwiv commented

I don't see anywhere in the wwiv source the word "unwanted", so I'm not sure what caused that.

wwiv commented

Do you keep getting new packets from those nodes in networkb.log too? Just making sure network1 isn't repopulating local.net repeatedly from some s###.net or P*.net

wwiv commented

@ericpareja are you experimenting by sending a file called unwanted.net to Jim?

I don't see anywhere in the wwiv source the word "unwanted", so I'm not sure what caused that.

Pretty sure that was Autosend.

Do you keep getting new packets from those nodes in networkb.log too? Just making sure network1 isn't repopulating local.net repeatedly from some s###.net or P*.net
networkb.log.zip

It's hard for me to say for sure. Attached is the last week.

wwiv commented

True, everything comes from Mark.

If you don't have any P*.net or any other .NET files (local.net p.net, s*.net) that are lying around, then it's likely the file isn't getting deleted from his bbs after send, and it just tries again. Try emailing him?

wwiv commented

Not on his bbs, the mailbox is full (I just tried)

autosend sends netmail to unsubscribed nodes that post to a hosted sub with the following text:

Subj: Unwanted Post Notification (Sub Type SUB)

Your system is sending posts to my system on sub type %s, which my
system hosts.  Your system is not a subscriber of this sub.  If you would
like to subscribe, please send an auto-request for the sub.

etc.

I noticed that in my wwivnet dir, there is an outbound packet bundle for @1 in s1.net which seems to be growing, even if I've been polling @1 and the connection keeps getting disconnected, networkb reports that s1.net was sent (?) but the file remains in place.

The in-randomnumberhere directory contains an s60.net packet, which seems to keep getting re-sent by @1.
The packet doesn't seem to be malformed or truncated but it doesn't get processed properly for network2(?) to remove the file and in-randomnumberhere directory.

I just watched the packed come in with the duplicates, getting them now from both @255 and @60. Must be an issue @1.
Not just e-mail. Also seeing events in the logs suppressing the duplicates in the subs.

wwiv commented

email mark - something may be borked on his file sharing setup

wwiv commented

I noticed that in my wwivnet dir, there is an outbound packet bundle for @1 in s1.net which seems to be growing, even if I've been polling @1 and the connection keeps getting disconnected, networkb reports that s1.net was sent (?) but the file remains in place.

a

I noticed that in my wwivnet dir, there is an outbound packet bundle for @1 in s1.net which seems to be growing, even if I've been polling @1 and the connection keeps getting disconnected, networkb reports that s1.net was sent (?) but the file remains in place.

Turn on --v=2 on your call to networkb to see if the delete is failing, also check permissions, maybe that's the issue?

No packets that I would recognize, but I do have an UNWANTED.NET file that I've never seen before.

AutoSend does this if UNWANTED_POST_NOTIFY is set in WWIV.INI (this is set by AUTOSCFG.EXE, I think). It does several things:

  1. sends e-mail to sysop of system sending posts to SUBs you host but their system isn't on the subscriber list.
  2. sends email to sysop of systems sending SUB posts to your system for which your system isn't subscribed to.
  3. creates a GFILES\UNWANTED.LOG.
  4. creates an UNWANTED.NET file similar to DEAD.NET in your network directory.