linux-avmb1:Sending certain faxes via capi4hylafax 4.2.5 and FritzCard DSL fails

Hans-Peter Jansen hpj at urpla.net
Fri Jul 21 14:50:38 CEST 2006


Hi,

diesen Bug hab ich letzte Woche ins SuSE Bugzilla eingetragen (#192098), 
daher englisch, leider bislang ohne Rückmeldung, deshalb ein erneuter 
Versuch hier auf der Liste:

OS: SuSE 9.3 Pro, Treiber: fcdsl2 3.11-07

Trying to send a 4 page postscript file via capi4hylafax and FritzCard DSL
fails continuesly, sometimes even without an error indication on the sending
side. I've backported the 10.1 hylafax package (including capi4hylafax) to 9.3,
since the latter suffered from several strange problems (by sending single 
pages successfully according to the log, but keeping them in failed state..). 

Sending single pages and receiving faxes seems to work fine. But sending the
attached postscript doc results in a pathologic case [sending log]:

Jul 13 13:01:12.67: [30640]: SESSION BEGIN 000000042 +49.6721.4089881
Jul 13 13:01:12.67: [30640]: SEND FAX: JOB 42 DEST 0672149934 COMMID 000000076
Jul 13 13:01:12.67: [30640]: Try to connect to fax number 0672149934 in Hylafax
mode on controller 1.
Jul 13 13:01:12.67: [30640]: Dial and starting transfer of TIFF-File
docq/doc42.ps;01 with fine resolution.
Jul 13 13:01:22.88: [30640]: Connection established.
Jul 13 13:01:22.88: [30640]:    StationID = SPED. JANSEN, BINGEN
Jul 13 13:01:22.88: [30640]:    BaudRate  = 14400
Jul 13 13:01:22.88: [30640]:    Flags     = HighRes, No_ECM
Jul 13 13:02:14.79: [30640]: Page 1 was sent.
Jul 13 13:03:01.67: [30640]: Page 2 was sent.
Jul 13 13:03:01.74: [30640]: Page 3 was sent.
Jul 13 13:03:01.76: [30640]: Page 4 was sent. - Last Page!
Jul 13 13:03:01.76: [30640]: Fax file completely transfered to CAPI.
Jul 13 13:03:03.80: [30640]: Connection dropped with Reason 0x3490 (Normal call
clearing).

Corresponding log on the receiver side (Elsa analog modem, currently running
hylafax-4.1.7, operating rock solid since years):

Jul 13 13:01:14.48: [ 3404]: SESSION BEGIN 00005469 49672149934
Jul 13 13:01:14.48: [ 3404]: HylaFAX (tm) Version 4.1.7
Jul 13 13:01:14.48: [ 3404]: <-- [4:ATA\r]
Jul 13 13:01:23.39: [ 3404]: --> [4:+FCO]
Jul 13 13:01:23.39: [ 3404]: ANSWER: FAX CONNECTION  DEVICE '/dev/ttyS0'
Jul 13 13:01:23.39: [ 3404]: RECV FAX: begin
Jul 13 13:01:23.39: [ 3404]: RECV FAX: CDPN 
Jul 13 13:01:28.03: [ 3404]: --> [27:+FTI:"    +49 6721 4089881"]
Jul 13 13:01:28.03: [ 3404]: REMOTE TSI "+49 6721 4089881"
Jul 13 13:01:28.03: [ 3404]: --> [20:+FCS:1,5,0,2,0,0,0,0]
Jul 13 13:01:28.03: [ 3404]: REMOTE wants 14400 bit/s
Jul 13 13:01:28.03: [ 3404]: REMOTE wants page width 1728 pixels in 215 mm
Jul 13 13:01:28.03: [ 3404]: REMOTE wants unlimited page length
Jul 13 13:01:28.03: [ 3404]: REMOTE wants 7.7 line/mm
Jul 13 13:01:28.03: [ 3404]: REMOTE wants 1-D MR
Jul 13 13:01:28.03: [ 3404]: --> [2:OK]
Jul 13 13:01:28.03: [ 3404]: <-- [7:AT+FDR\r]
Jul 13 13:01:29.91: [ 3404]: --> [7:CONNECT]
Jul 13 13:01:29.91: [ 3404]: RECV: begin page
Jul 13 13:01:29.91: [ 3404]: RECV: send trigger 022
Jul 13 13:01:29.91: [ 3404]: <-- data [1]
Jul 13 13:01:48.09: [ 3404]: RECV: 32733 bytes of data, 918 total lines
Jul 13 13:02:06.24: [ 3404]: RECV: 32739 bytes of data, 1762 total lines
Jul 13 13:02:24.41: [ 3404]: RECV: 27821 bytes of data, 2202 total lines
Jul 13 13:02:24.41: [ 3404]: --> [17:+FPS:1,8AE,11,0,0]
Jul 13 13:02:25.62: [ 3404]: --> [6:+FET:0]
Jul 13 13:02:25.62: [ 3404]: RECV recv MPS (more pages, same document)
Jul 13 13:02:25.62: [ 3404]: --> [2:OK]
Jul 13 13:02:25.62: [ 3404]: RECV send MCF (message confirmation)
Jul 13 13:02:25.62: [ 3404]: RECV FAX (00005469): from +49 6721 4089881, page 1
in 0:57, INF, 7.7 line/mm, 1-D MR, 14400 bit/s
Jul 13 13:02:25.62: [ 3404]: <-- [7:AT+FDR\r]
Jul 13 13:02:27.70: [ 3404]: --> [7:CONNECT]
Jul 13 13:02:27.70: [ 3404]: RECV: begin page
Jul 13 13:02:27.70: [ 3404]: RECV: send trigger 022
Jul 13 13:02:27.70: [ 3404]: <-- data [1]
Jul 13 13:02:51.99: [ 3404]: RECV: 25269 bytes of data, 594 total lines
Jul 13 13:02:51.99: [ 3404]: --> [17:+FPS:2,28A,37,0,0]
Jul 13 13:03:00.50: [ 3404]: --> [7:+FHS:A0]
Jul 13 13:03:00.50: [ 3404]: REMOTE HANGUP: Unspecified Phase D error (code A0)
Jul 13 13:03:01.71: [ 3404]: --> [2:OK]
Jul 13 13:03:01.71: [ 3404]: RECV FAX (00005469): recvq/fax00034.tif from +49
6721 4089881, route to <unspecified>, 1 pages in 1:38
Jul 13 13:03:01.71: [ 3404]: RECV FAX: Unspecified Phase D error
Jul 13 13:03:01.71: [ 3404]: RECV FAX (00005469): session with +49 6721 4089881
terminated abnormally: Unspecified Phase D error
Jul 13 13:03:01.72: [ 3404]: RECV FAX: bin/faxrcvd "recvq/fax00034.tif" "ttyS0"
"00005469" "Unspecified Phase D error" "" "" ""
Jul 13 13:03:01.97: [ 3404]: RECV FAX: end
Jul 13 13:03:01.97: [ 3404]: SESSION END

See, it only receives one page and a part of the second, than fails, but sender
thinks, it succeeded! 

Also, [sender] syslog gives no indication about any problems:
Jul 13 13:01:11 sugar FaxQueuer[17457]: SUBMIT JOB 42
Jul 13 13:01:13 sugar isdnlog: Jul 13 13:01:13 * tei 98 calling +49 6721/49934,
Bingen with +49 6721/4089881, Bingen  RING (3.1 kHz audio)
Jul 13 13:01:14 sugar isdnlog: Jul 13 13:01:14 tei 98 calling +49 6721/49934,
Bingen with +49 6721/4089881, Bingen  Time:Thu Jul 13 13:01:00 2006
Jul 13 13:01:14 sugar isdnlog: Jul 13 13:01:14 tei 98 calling +49 6721/49934,
Bingen with +49 6721/4089881, Bingen  COLP +49 6721/49934, Bingen
Jul 13 13:01:14 sugar isdnlog: Jul 13 13:01:14 tei 98 calling +49 6721/49934,
Bingen with +49 6721/4089881, Bingen  CONNECT (3.1 kHz audio)
Jul 13 13:01:14 sugar isdnlog: Jul 13 13:01:14 tei 98 calling +49 6721/49934,
Bingen with +49 6721/4089881, Bingen  CHARGE: 5.997 242/90s = 3.998 242/Min
(DTAG T-ISDN Standard, City, Werktag (Donnerstag),
 Tag)
Jul 13 13:01:14 sugar isdnlog: Jul 13 13:01:14 tei 98 calling +49 6721/49934,
Bingen with +49 6721/4089881, Bingen  HINT: Better use 0190037:Fonfux, 1.280
242/60s = 1.280 242/Min, saving 3.198 242/Min
Jul 13 13:01:14 sugar isdnlog: Jul 13 13:01:14 tei 98 calling +49 6721/49934,
Bingen with +49 6721/4089881, Bingen  1.CI 5.997 242 (now)
Jul 13 13:01:14 sugar isdnlog: Jul 13 13:01:14 tei 98 calling +49 6721/49934,
Bingen with +49 6721/4089881, Bingen  NEXT CI AFTER 01:30 (DTAG T-ISDN
Standard, City, Werktag (Donnerstag), Tag)
Jul 13 13:01:14 sugar kernel: capilib_new_ncci: kcapi: appl 6 ncci 0x20201 up
Jul 13 13:02:45 sugar isdnlog: Jul 13 13:02:45 tei 98 calling +49 6721/49934,
Bingen with +49 6721/4089881, Bingen  2.CI 11.994 242 (after  0:01:31) 
Jul 13 13:03:01 sugar kernel: kcapi: appl 6 ncci 0x20201 down
Jul 13 13:03:03 sugar isdnlog: Jul 13 13:03:03 tei 98 calling +49 6721/49934,
Bingen with +49 6721/4089881, Bingen  HINT: Cheapest booked 0190037:Fonfux
2.560 242 (would save 9.434 242)
Jul 13 13:03:03 sugar isdnlog: Jul 13 13:03:03 tei 98 calling +49 6721/49934,
Bingen with +49 6721/4089881, Bingen  HINT: Overall cheapest 01041:HanseNet
allFon Talk4Free 0.000 242 (would save 11.994 242)
Jul 13 13:03:03 sugar isdnlog: Jul 13 13:03:03 tei 98 calling +49 6721/49934,
Bingen with +49 6721/4089881, Bingen  HINT: LCR:FAILED
Jul 13 13:03:03 sugar isdnlog: Jul 13 13:03:03 tei 98 calling +49 6721/49934,
Bingen with +49 6721/4089881, Bingen  HANGUP (2 CI 11.994 242; 2 EH EUR  0.124 
0:01:49)

I've no idea, how to preceed with this problem since I was just lucky to
control both sides (and to test throughout).

capiinfo:
Number of Controllers : 2
Controller 1:
Manufacturer: AVM-GmbH
CAPI Version: 2.0
Manufacturer Version: 3.11-07  (49.23)
Serial Number: 0000000
BChannels: 2
Global Options: 0x00000039
   internal controller supported
   DTMF supported
   Supplementary Services supported
   channel allocation supported (leased lines)
B1 protocols support: 0x4000011f
   64 kbit/s with HDLC framing
   64 kbit/s bit-transparent operation
   V.110 asynconous operation with start/stop byte framing
   V.110 synconous operation with HDLC framing
   T.30 modem for fax group 3
   Modem asyncronous operation with start/stop byte framing
B2 protocols support: 0x00000b1b
   ISO 7776 (X.75 SLP)
   Transparent
   LAPD with Q.921 for D channel X.25 (SAPI 16)
   T.30 for fax group 3
   ISO 7776 (X.75 SLP) with V.42bis compression
   V.120 asyncronous mode
   V.120 bit-transparent mode
B3 protocols support: 0x800000bf
   Transparent
   T.90NL, T.70NL, T.90
   ISO 8208 (X.25 DTE-DTE)
   X.25 DCE
   T.30 for fax group 3
   T.30 for fax group 3 with extensions
   Modem

  0100
  0200
  39000000
  1f010040
  1b0b0000
  bf000080
  00000000 00000000 00000000 00000000 00000000 00000000
  01000001 00020000 00000000 00000000 00000000

Supplementary services support: 0x000003ff
   Hold / Retrieve
   Terminal Portability
   ECT
   3PTY
   Call Forwarding
   Call Deflection
   MCID
   CCBS

Controller 2:
Manufacturer: AVM-GmbH
CAPI Version: 2.0
Manufacturer Version: 3.11-07  (49.23)
Serial Number: 0000000
BChannels: 1
Global Options: 0x00000001
   internal controller supported
B1 protocols support: 0x10000000
B2 protocols support: 0x40000002
   Transparent
B3 protocols support: 0x40000001
   Transparent

  0100
  0100
  01000000
  00000010
  02000040
  01000040
  00000000 00000000 00000000 00000000 00000000 00000000
  01000001 00020000 00000000 00000000 00000000

Das gesendete Dokument ist hier verfügbar:
ftp://urpla.net/print.ps

Irgendeine Idee irgend jemand, was hier schiefgeht? Sind euch ähnliche 
Effekte bekannt?

Freue mich über jeden Hinweis, der zur Ergreifung des Täters führt ;-)
Pete




More information about the linux-avmb1 mailing list